Build: https://jenkins.thetaphi.de/job/Lucene-Solr-7.x-Linux/1329/
Java: 32bit/jdk1.8.0_162 -client -XX:+UseG1GC
4 tests failed.
FAILED: junit.framework.TestSuite.org.apache.solr.cloud.rule.RulesTest
Error Message:
1 thread leaked from SUITE scope at org.apache.solr.cloud.rule.RulesTest:
1) Thread[id=16595, name=qtp27345429-16595, state=TIMED_WAITING,
group=TGRP-RulesTest] at sun.misc.Unsafe.park(Native Method) at
java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215)
at
java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2163)
at
org.eclipse.jetty.util.thread.ReservedThreadExecutor$ReservedThread.reservedWait(ReservedThreadExecutor.java:308)
at
org.eclipse.jetty.util.thread.ReservedThreadExecutor$ReservedThread.run(ReservedThreadExecutor.java:373)
at
org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:708)
at
org.eclipse.jetty.util.thread.QueuedThreadPool$2.run(QueuedThreadPool.java:626)
at java.lang.Thread.run(Thread.java:748)
Stack Trace:
com.carrotsearch.randomizedtesting.ThreadLeakError: 1 thread leaked from SUITE
scope at org.apache.solr.cloud.rule.RulesTest:
1) Thread[id=16595, name=qtp27345429-16595, state=TIMED_WAITING,
group=TGRP-RulesTest]
at sun.misc.Unsafe.park(Native Method)
at
java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215)
at
java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2163)
at
org.eclipse.jetty.util.thread.ReservedThreadExecutor$ReservedThread.reservedWait(ReservedThreadExecutor.java:308)
at
org.eclipse.jetty.util.thread.ReservedThreadExecutor$ReservedThread.run(ReservedThreadExecutor.java:373)
at
org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:708)
at
org.eclipse.jetty.util.thread.QueuedThreadPool$2.run(QueuedThreadPool.java:626)
at java.lang.Thread.run(Thread.java:748)
at __randomizedtesting.SeedInfo.seed([EBBA7F4A24CDA47F]:0)
FAILED: junit.framework.TestSuite.org.apache.solr.cloud.rule.RulesTest
Error Message:
There are still zombie threads that couldn't be terminated: 1)
Thread[id=16595, name=qtp27345429-16595, state=TIMED_WAITING,
group=TGRP-RulesTest] at sun.misc.Unsafe.park(Native Method) at
java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215)
at
java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2163)
at
org.eclipse.jetty.util.thread.ReservedThreadExecutor$ReservedThread.reservedWait(ReservedThreadExecutor.java:308)
at
org.eclipse.jetty.util.thread.ReservedThreadExecutor$ReservedThread.run(ReservedThreadExecutor.java:373)
at
org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:708)
at
org.eclipse.jetty.util.thread.QueuedThreadPool$2.run(QueuedThreadPool.java:626)
at java.lang.Thread.run(Thread.java:748)
Stack Trace:
com.carrotsearch.randomizedtesting.ThreadLeakError: There are still zombie
threads that couldn't be terminated:
1) Thread[id=16595, name=qtp27345429-16595, state=TIMED_WAITING,
group=TGRP-RulesTest]
at sun.misc.Unsafe.park(Native Method)
at
java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215)
at
java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2163)
at
org.eclipse.jetty.util.thread.ReservedThreadExecutor$ReservedThread.reservedWait(ReservedThreadExecutor.java:308)
at
org.eclipse.jetty.util.thread.ReservedThreadExecutor$ReservedThread.run(ReservedThreadExecutor.java:373)
at
org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:708)
at
org.eclipse.jetty.util.thread.QueuedThreadPool$2.run(QueuedThreadPool.java:626)
at java.lang.Thread.run(Thread.java:748)
at __randomizedtesting.SeedInfo.seed([EBBA7F4A24CDA47F]:0)
FAILED: org.apache.solr.cloud.ReplaceNodeNoTargetTest.test
Error Message:
Stack Trace:
java.lang.AssertionError
at
__randomizedtesting.SeedInfo.seed([EBBA7F4A24CDA47F:63EE40908A31C987]:0)
at org.junit.Assert.fail(Assert.java:92)
at org.junit.Assert.assertTrue(Assert.java:43)
at org.junit.Assert.assertTrue(Assert.java:54)
at
org.apache.solr.cloud.ReplaceNodeNoTargetTest.test(ReplaceNodeNoTargetTest.java:92)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at
sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:498)
at
com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1737)
at
com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:934)
at
com.carrotsearch.randomizedtesting.RandomizedRunner$9.evaluate(RandomizedRunner.java:970)
at
com.carrotsearch.randomizedtesting.RandomizedRunner$10.evaluate(RandomizedRunner.java:984)
at
com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
at
org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:49)
at
org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
at
org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:48)
at
org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
at
org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
at
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at
com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368)
at
com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:817)
at
com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:468)
at
com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:943)
at
com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:829)
at
com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:879)
at
com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:890)
at
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at
com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
at
org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
at
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at
org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:41)
at
com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
at
com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
at
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at
org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:53)
at
org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
at
org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
at
org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:54)
at
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at
com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368)
at java.lang.Thread.run(Thread.java:748)
FAILED:
org.apache.solr.cloud.autoscaling.ComputePlanActionTest.testSelectedCollections
Error Message:
The operations computed by ComputePlanAction should not be
nullSolrClientNodeStateProvider.DEBUG{AFTER_ACTION=[compute_plan, null],
BEFORE_ACTION=[compute_plan, null]}
Stack Trace:
java.lang.AssertionError: The operations computed by ComputePlanAction should
not be nullSolrClientNodeStateProvider.DEBUG{AFTER_ACTION=[compute_plan, null],
BEFORE_ACTION=[compute_plan, null]}
at
__randomizedtesting.SeedInfo.seed([EBBA7F4A24CDA47F:D1149A931AA97D11]:0)
at org.junit.Assert.fail(Assert.java:93)
at org.junit.Assert.assertTrue(Assert.java:43)
at org.junit.Assert.assertNotNull(Assert.java:526)
at
org.apache.solr.cloud.autoscaling.ComputePlanActionTest.testSelectedCollections(ComputePlanActionTest.java:469)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at
sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:498)
at
com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1737)
at
com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:934)
at
com.carrotsearch.randomizedtesting.RandomizedRunner$9.evaluate(RandomizedRunner.java:970)
at
com.carrotsearch.randomizedtesting.RandomizedRunner$10.evaluate(RandomizedRunner.java:984)
at
com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
at
org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:49)
at
org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
at
org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:48)
at
org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
at
org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
at
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at
com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368)
at
com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:817)
at
com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:468)
at
com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:943)
at
com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:829)
at
com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:879)
at
com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:890)
at
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at
com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
at
org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
at
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at
org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:41)
at
com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
at
com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
at
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at
org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:53)
at
org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
at
org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
at
org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:54)
at
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at
com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368)
at java.lang.Thread.run(Thread.java:748)
Build Log:
[...truncated 12471 lines...]
[junit4] Suite: org.apache.solr.cloud.autoscaling.ComputePlanActionTest
[junit4] 2> Creating dataDir:
/home/jenkins/workspace/Lucene-Solr-7.x-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.autoscaling.ComputePlanActionTest_EBBA7F4A24CDA47F-001/init-core-data-001
[junit4] 2> 613902 INFO
(SUITE-ComputePlanActionTest-seed#[EBBA7F4A24CDA47F]-worker) [ ]
o.a.s.SolrTestCaseJ4 Using PointFields (NUMERIC_POINTS_SYSPROP=true)
w/NUMERIC_DOCVALUES_SYSPROP=false
[junit4] 2> 613903 INFO
(SUITE-ComputePlanActionTest-seed#[EBBA7F4A24CDA47F]-worker) [ ]
o.a.s.SolrTestCaseJ4 Randomized ssl (true) and clientAuth (true) via:
@org.apache.solr.util.RandomizeSSL(reason=, ssl=NaN, value=NaN, clientAuth=NaN)
[junit4] 2> 613904 INFO
(SUITE-ComputePlanActionTest-seed#[EBBA7F4A24CDA47F]-worker) [ ]
o.a.s.SolrTestCaseJ4 SecureRandom sanity checks:
test.solr.allowed.securerandom=null & java.security.egd=file:/dev/./urandom
[junit4] 2> 613904 INFO
(SUITE-ComputePlanActionTest-seed#[EBBA7F4A24CDA47F]-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/J0/temp/solr.cloud.autoscaling.ComputePlanActionTest_EBBA7F4A24CDA47F-001/tempDir-001
[junit4] 2> 613904 INFO
(SUITE-ComputePlanActionTest-seed#[EBBA7F4A24CDA47F]-worker) [ ]
o.a.s.c.ZkTestServer STARTING ZK TEST SERVER
[junit4] 2> 613905 INFO (Thread-917) [ ] o.a.s.c.ZkTestServer client
port:0.0.0.0/0.0.0.0:0
[junit4] 2> 613905 INFO (Thread-917) [ ] o.a.s.c.ZkTestServer Starting
server
[junit4] 2> 613906 ERROR (Thread-917) [ ] 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> 614005 INFO
(SUITE-ComputePlanActionTest-seed#[EBBA7F4A24CDA47F]-worker) [ ]
o.a.s.c.ZkTestServer start zk server on port:44701
[junit4] 2> 614007 INFO (zkConnectionManagerCallback-994-thread-1) [ ]
o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 614011 INFO (jetty-launcher-991-thread-1) [ ]
o.e.j.s.Server jetty-9.4.8.v20171121, build timestamp:
2017-11-21T10:27:37-11:00, git hash: 82b8fb23f757335bb3329d540ce37a2a2615f0a8
[junit4] 2> 614014 INFO (jetty-launcher-991-thread-1) [ ]
o.e.j.s.session DefaultSessionIdManager workerName=node0
[junit4] 2> 614014 INFO (jetty-launcher-991-thread-1) [ ]
o.e.j.s.session No SessionScavenger set, using defaults
[junit4] 2> 614014 INFO (jetty-launcher-991-thread-1) [ ]
o.e.j.s.session Scavenging every 600000ms
[junit4] 2> 614014 INFO (jetty-launcher-991-thread-1) [ ]
o.e.j.s.h.ContextHandler Started
o.e.j.s.ServletContextHandler@176d55f{/solr,null,AVAILABLE}
[junit4] 2> 614017 INFO (jetty-launcher-991-thread-1) [ ]
o.e.j.s.AbstractConnector Started ServerConnector@9ba1c9{SSL,[ssl,
http/1.1]}{127.0.0.1:34915}
[junit4] 2> 614017 INFO (jetty-launcher-991-thread-1) [ ]
o.e.j.s.Server Started @615336ms
[junit4] 2> 614017 INFO (jetty-launcher-991-thread-1) [ ]
o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr,
hostPort=34915}
[junit4] 2> 614018 ERROR (jetty-launcher-991-thread-1) [ ]
o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be
missing or incomplete.
[junit4] 2> 614018 INFO (jetty-launcher-991-thread-1) [ ]
o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr™ version
7.3.0
[junit4] 2> 614018 INFO (jetty-launcher-991-thread-1) [ ]
o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 614018 INFO (jetty-launcher-991-thread-1) [ ]
o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 614018 INFO (jetty-launcher-991-thread-1) [ ]
o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time:
2018-02-10T11:58:16.509Z
[junit4] 2> 614022 INFO (zkConnectionManagerCallback-996-thread-1) [ ]
o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 614023 INFO (jetty-launcher-991-thread-1) [ ]
o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 614032 INFO (jetty-launcher-991-thread-1) [ ]
o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:44701/solr
[junit4] 2> 614033 INFO (zkConnectionManagerCallback-1000-thread-1) [
] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 614035 INFO
(zkConnectionManagerCallback-1002-thread-1-processing-n:127.0.0.1:34915_solr)
[n:127.0.0.1:34915_solr ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 614126 INFO (jetty-launcher-991-thread-1)
[n:127.0.0.1:34915_solr ] o.a.s.c.Overseer Overseer (id=null) closing
[junit4] 2> 614126 INFO (jetty-launcher-991-thread-1)
[n:127.0.0.1:34915_solr ] o.a.s.c.OverseerElectionContext I am going to be
the leader 127.0.0.1:34915_solr
[junit4] 2> 614127 INFO (jetty-launcher-991-thread-1)
[n:127.0.0.1:34915_solr ] o.a.s.c.Overseer Overseer
(id=72124903234600963-127.0.0.1:34915_solr-n_0000000000) starting
[junit4] 2> 614131 DEBUG
(OverseerStateUpdate-72124903234600963-127.0.0.1:34915_solr-n_0000000000)
[n:127.0.0.1:34915_solr ] o.a.s.c.Overseer Starting to work on the main queue
[junit4] 2> 614132 INFO (jetty-launcher-991-thread-1)
[n:127.0.0.1:34915_solr ] o.a.s.c.ZkController Register node as live in
ZooKeeper:/live_nodes/127.0.0.1:34915_solr
[junit4] 2> 614132 DEBUG
(OverseerAutoScalingTriggerThread-72124903234600963-127.0.0.1:34915_solr-n_0000000000)
[n:127.0.0.1:34915_solr ] o.a.s.c.a.OverseerTriggerThread Adding
.autoAddReplicas trigger
[junit4] 2> 614132 INFO
(OverseerStateUpdate-72124903234600963-127.0.0.1:34915_solr-n_0000000000)
[n:127.0.0.1:34915_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (0) -> (1)
[junit4] 2> 614133 DEBUG
(OverseerAutoScalingTriggerThread-72124903234600963-127.0.0.1:34915_solr-n_0000000000)
[n:127.0.0.1:34915_solr ] o.a.s.c.a.OverseerTriggerThread Refreshing
/autoscaling.json with znode version 1
[junit4] 2> 614133 DEBUG
(OverseerAutoScalingTriggerThread-72124903234600963-127.0.0.1:34915_solr-n_0000000000)
[n:127.0.0.1:34915_solr ] o.a.s.c.a.NodeLostTrigger Initial livenodes:
[127.0.0.1:34915_solr]
[junit4] 2> 614133 DEBUG
(OverseerAutoScalingTriggerThread-72124903234600963-127.0.0.1:34915_solr-n_0000000000)
[n:127.0.0.1:34915_solr ] o.a.s.c.a.OverseerTriggerThread Current
znodeVersion 1, lastZnodeVersion -1
[junit4] 2> 614133 DEBUG
(OverseerAutoScalingTriggerThread-72124903234600963-127.0.0.1:34915_solr-n_0000000000)
[n:127.0.0.1:34915_solr ] o.a.s.c.a.OverseerTriggerThread Processed trigger
updates upto znodeVersion 1
[junit4] 2> 614139 DEBUG
(OverseerAutoScalingTriggerThread-72124903234600963-127.0.0.1:34915_solr-n_0000000000)
[n:127.0.0.1:34915_solr ] o.a.s.c.a.OverseerTriggerThread -- clean old
nodeAdded markers
[junit4] 2> 614139 DEBUG
(OverseerAutoScalingTriggerThread-72124903234600963-127.0.0.1:34915_solr-n_0000000000)
[n:127.0.0.1:34915_solr ] o.a.s.c.a.OverseerTriggerThread Current
znodeVersion 1, lastZnodeVersion 1
[junit4] 2> 614140 DEBUG (ScheduledTrigger-1682-thread-1)
[n:127.0.0.1:34915_solr ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger:
.auto_add_replicas with currently live nodes: 1
[junit4] 2> 614328 INFO (jetty-launcher-991-thread-1)
[n:127.0.0.1:34915_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for
'solr_34915.solr.node' (registry 'solr.node') enabled at server:
com.sun.jmx.mbeanserver.JmxMBeanServer@12fe9f8
[junit4] 2> 614337 INFO (jetty-launcher-991-thread-1)
[n:127.0.0.1:34915_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for
'solr_34915.solr.jvm' (registry 'solr.jvm') enabled at server:
com.sun.jmx.mbeanserver.JmxMBeanServer@12fe9f8
[junit4] 2> 614337 INFO (jetty-launcher-991-thread-1)
[n:127.0.0.1:34915_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for
'solr_34915.solr.jetty' (registry 'solr.jetty') enabled at server:
com.sun.jmx.mbeanserver.JmxMBeanServer@12fe9f8
[junit4] 2> 614339 INFO (jetty-launcher-991-thread-1)
[n:127.0.0.1:34915_solr ] o.a.s.c.CorePropertiesLocator Found 0 core
definitions underneath
/home/jenkins/workspace/Lucene-Solr-7.x-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.autoscaling.ComputePlanActionTest_EBBA7F4A24CDA47F-001/tempDir-001/node1/.
[junit4] 2> 614356 INFO (zkConnectionManagerCallback-1006-thread-1) [
] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 614360 INFO (zkConnectionManagerCallback-1010-thread-1) [
] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 614361 INFO
(SUITE-ComputePlanActionTest-seed#[EBBA7F4A24CDA47F]-worker) [ ]
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 614362 INFO
(SUITE-ComputePlanActionTest-seed#[EBBA7F4A24CDA47F]-worker) [ ]
o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:44701/solr ready
[junit4] 2> 614372 INFO
(TEST-ComputePlanActionTest.testNodeAdded-seed#[EBBA7F4A24CDA47F]) [ ]
o.a.s.SolrTestCaseJ4 ###Starting testNodeAdded
[junit4] 2> 614372 DEBUG
(zkCallback-1001-thread-1-processing-n:127.0.0.1:34915_solr)
[n:127.0.0.1:34915_solr ] o.a.s.c.a.OverseerTriggerThread Refreshing
/autoscaling.json with znode version 2
[junit4] 2> 614372 DEBUG
(OverseerAutoScalingTriggerThread-72124903234600963-127.0.0.1:34915_solr-n_0000000000)
[n:127.0.0.1:34915_solr ] o.a.s.c.a.OverseerTriggerThread Processed trigger
updates upto znodeVersion 2
[junit4] 2> 614373 INFO
(TEST-ComputePlanActionTest.testNodeAdded-seed#[EBBA7F4A24CDA47F]) [ ]
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 614373 DEBUG
(OverseerAutoScalingTriggerThread-72124903234600963-127.0.0.1:34915_solr-n_0000000000)
[n:127.0.0.1:34915_solr ] o.a.s.c.a.OverseerTriggerThread -- clean old
nodeLost markers
[junit4] 2> 614374 DEBUG
(OverseerAutoScalingTriggerThread-72124903234600963-127.0.0.1:34915_solr-n_0000000000)
[n:127.0.0.1:34915_solr ] o.a.s.c.a.OverseerTriggerThread -- clean old
nodeAdded markers
[junit4] 2> 614374 DEBUG
(OverseerAutoScalingTriggerThread-72124903234600963-127.0.0.1:34915_solr-n_0000000000)
[n:127.0.0.1:34915_solr ] o.a.s.c.a.OverseerTriggerThread Current
znodeVersion 2, lastZnodeVersion 2
[junit4] 2> 614449 INFO (qtp14049233-4203) [n:127.0.0.1:34915_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> 614450 DEBUG (qtp14049233-4207) [n:127.0.0.1:34915_solr ]
o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
[junit4] 2> 614450 INFO (qtp14049233-4207) [n:127.0.0.1:34915_solr ]
o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/autoscaling
params={wt=javabin&version=2} status=0 QTime=9
[junit4] 2> 614450 DEBUG
(zkCallback-1001-thread-1-processing-n:127.0.0.1:34915_solr)
[n:127.0.0.1:34915_solr ] o.a.s.c.a.OverseerTriggerThread Refreshing
/autoscaling.json with znode version 3
[junit4] 2> 614450 DEBUG
(OverseerAutoScalingTriggerThread-72124903234600963-127.0.0.1:34915_solr-n_0000000000)
[n:127.0.0.1:34915_solr ] o.a.s.c.a.OverseerTriggerThread Processed trigger
updates upto znodeVersion 3
[junit4] 2> 614451 DEBUG
(OverseerAutoScalingTriggerThread-72124903234600963-127.0.0.1:34915_solr-n_0000000000)
[n:127.0.0.1:34915_solr ] o.a.s.c.a.OverseerTriggerThread -- clean old
nodeLost markers
[junit4] 2> 614451 DEBUG
(OverseerAutoScalingTriggerThread-72124903234600963-127.0.0.1:34915_solr-n_0000000000)
[n:127.0.0.1:34915_solr ] o.a.s.c.a.OverseerTriggerThread -- clean old
nodeAdded markers
[junit4] 2> 614451 DEBUG
(OverseerAutoScalingTriggerThread-72124903234600963-127.0.0.1:34915_solr-n_0000000000)
[n:127.0.0.1:34915_solr ] o.a.s.c.a.OverseerTriggerThread Current
znodeVersion 3, lastZnodeVersion 3
[junit4] 2> 614456 INFO (qtp14049233-4208) [n:127.0.0.1:34915_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> 614457 DEBUG (qtp14049233-4209) [n:127.0.0.1:34915_solr ]
o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
[junit4] 2> 614458 INFO (qtp14049233-4209) [n:127.0.0.1:34915_solr ]
o.a.s.s.HttpSolrCall [admin] webapp=null path=/cluster/autoscaling
params={wt=javabin&version=2} status=0 QTime=5
[junit4] 2> 614458 DEBUG
(zkCallback-1001-thread-1-processing-n:127.0.0.1:34915_solr)
[n:127.0.0.1:34915_solr ] o.a.s.c.a.OverseerTriggerThread Refreshing
/autoscaling.json with znode version 4
[junit4] 2> 614458 DEBUG
(OverseerAutoScalingTriggerThread-72124903234600963-127.0.0.1:34915_solr-n_0000000000)
[n:127.0.0.1:34915_solr ] o.a.s.c.a.OverseerTriggerThread Processed trigger
updates upto znodeVersion 4
[junit4] 2> 614458 DEBUG
(OverseerAutoScalingTriggerThread-72124903234600963-127.0.0.1:34915_solr-n_0000000000)
[n:127.0.0.1:34915_solr ] o.a.s.c.a.OverseerTriggerThread -- clean old
nodeLost markers
[junit4] 2> 614460 DEBUG
(OverseerAutoScalingTriggerThread-72124903234600963-127.0.0.1:34915_solr-n_0000000000)
[n:127.0.0.1:34915_solr ] o.a.s.c.a.OverseerTriggerThread -- clean old
nodeAdded markers
[junit4] 2> 614460 DEBUG
(OverseerAutoScalingTriggerThread-72124903234600963-127.0.0.1:34915_solr-n_0000000000)
[n:127.0.0.1:34915_solr ] o.a.s.c.a.OverseerTriggerThread Current
znodeVersion 4, lastZnodeVersion 4
[junit4] 2> 614463 INFO (qtp14049233-4203) [n:127.0.0.1:34915_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> 614463 DEBUG (qtp14049233-4207) [n:127.0.0.1:34915_solr ]
o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
[junit4] 2> 614464 INFO (qtp14049233-4207) [n:127.0.0.1:34915_solr ]
o.a.s.s.HttpSolrCall [admin] webapp=null path=/cluster/autoscaling
params={wt=javabin&version=2} status=0 QTime=3
[junit4] 2> 614464 DEBUG
(zkCallback-1001-thread-1-processing-n:127.0.0.1:34915_solr)
[n:127.0.0.1:34915_solr ] o.a.s.c.a.OverseerTriggerThread Refreshing
/autoscaling.json with znode version 5
[junit4] 2> 614467 DEBUG
(zkCallback-1001-thread-1-processing-n:127.0.0.1:34915_solr)
[n:127.0.0.1:34915_solr ] o.a.s.c.a.NodeAddedTrigger Initial livenodes:
[127.0.0.1:34915_solr]
[junit4] 2> 614467 DEBUG
(zkCallback-1001-thread-1-processing-n:127.0.0.1:34915_solr)
[n:127.0.0.1:34915_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> 614467 DEBUG
(OverseerAutoScalingTriggerThread-72124903234600963-127.0.0.1:34915_solr-n_0000000000)
[n:127.0.0.1:34915_solr ] o.a.s.c.a.OverseerTriggerThread Processed trigger
updates upto znodeVersion 5
[junit4] 2> 614468 INFO (qtp14049233-4208) [n:127.0.0.1:34915_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> 614468 DEBUG (qtp14049233-4209) [n:127.0.0.1:34915_solr ]
o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
[junit4] 2> 614469 INFO (qtp14049233-4209) [n:127.0.0.1:34915_solr ]
o.a.s.s.HttpSolrCall [admin] webapp=null path=/cluster/autoscaling
params={wt=javabin&version=2} status=0 QTime=3
[junit4] 2> 614469 DEBUG
(zkCallback-1001-thread-1-processing-n:127.0.0.1:34915_solr)
[n:127.0.0.1:34915_solr ] o.a.s.c.a.OverseerTriggerThread Refreshing
/autoscaling.json with znode version 6
[junit4] 2> 614469 DEBUG
(OverseerAutoScalingTriggerThread-72124903234600963-127.0.0.1:34915_solr-n_0000000000)
[n:127.0.0.1:34915_solr ] o.a.s.c.a.OverseerTriggerThread -- clean old
nodeLost markers
[junit4] 2> 614470 DEBUG
(zkCallback-1001-thread-1-processing-n:127.0.0.1:34915_solr)
[n:127.0.0.1:34915_solr ] o.a.s.c.a.NodeAddedTrigger Initial livenodes:
[127.0.0.1:34915_solr]
[junit4] 2> 614470 DEBUG
(zkCallback-1001-thread-1-processing-n:127.0.0.1:34915_solr)
[n:127.0.0.1:34915_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> 614470 DEBUG
(OverseerAutoScalingTriggerThread-72124903234600963-127.0.0.1:34915_solr-n_0000000000)
[n:127.0.0.1:34915_solr ] o.a.s.c.a.OverseerTriggerThread Current
znodeVersion 6, lastZnodeVersion 5
[junit4] 2> 614470 DEBUG
(OverseerAutoScalingTriggerThread-72124903234600963-127.0.0.1:34915_solr-n_0000000000)
[n:127.0.0.1:34915_solr ] o.a.s.c.a.OverseerTriggerThread Processed trigger
updates upto znodeVersion 6
[junit4] 2> 614470 DEBUG (ScheduledTrigger-1682-thread-1)
[n:127.0.0.1:34915_solr ] o.a.s.c.a.NodeAddedTrigger Running
NodeAddedTrigger node_added_trigger
[junit4] 2> 614470 DEBUG (ScheduledTrigger-1682-thread-1)
[n:127.0.0.1:34915_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 1
[junit4] 2> 614470 DEBUG
(OverseerAutoScalingTriggerThread-72124903234600963-127.0.0.1:34915_solr-n_0000000000)
[n:127.0.0.1:34915_solr ] o.a.s.c.a.OverseerTriggerThread -- clean old
nodeLost markers
[junit4] 2> 614470 DEBUG
(OverseerAutoScalingTriggerThread-72124903234600963-127.0.0.1:34915_solr-n_0000000000)
[n:127.0.0.1:34915_solr ] o.a.s.c.a.OverseerTriggerThread Current
znodeVersion 6, lastZnodeVersion 6
[junit4] 2> 614471 INFO (qtp14049233-4207) [n:127.0.0.1:34915_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> 614476 INFO
(OverseerThreadFactory-1684-thread-1-processing-n:127.0.0.1:34915_solr)
[n:127.0.0.1:34915_solr ] o.a.s.c.a.c.CreateCollectionCmd Create collection
testNodeAdded
[junit4] 2> 614476 WARN
(OverseerThreadFactory-1684-thread-1-processing-n:127.0.0.1:34915_solr)
[n:127.0.0.1:34915_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> 614478 INFO (qtp14049233-4203) [n:127.0.0.1:34915_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> 614479 INFO
(OverseerThreadFactory-1684-thread-1-processing-n:127.0.0.1:34915_solr)
[n:127.0.0.1:34915_solr ] o.a.s.c.s.c.a.PolicyHelper returnSession,
curr-time 1027057407 sessionWrapper.createTime 1027057407546156,
this.sessionWrapper.createTime 1027057407546156
[junit4] 2> 614481 DEBUG
(OverseerStateUpdate-72124903234600963-127.0.0.1:34915_solr-n_0000000000)
[n:127.0.0.1:34915_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> 614482 DEBUG
(OverseerStateUpdate-72124903234600963-127.0.0.1:34915_solr-n_0000000000)
[n:127.0.0.1:34915_solr ] o.a.s.c.o.ClusterStateMutator building a new
cName: testNodeAdded
[junit4] 2> 614482 DEBUG
(OverseerStateUpdate-72124903234600963-127.0.0.1:34915_solr-n_0000000000)
[n:127.0.0.1:34915_solr ] o.a.s.c.o.ZkStateWriter going to create_collection
/collections/testNodeAdded/state.json
[junit4] 2> 614584 DEBUG
(OverseerStateUpdate-72124903234600963-127.0.0.1:34915_solr-n_0000000000)
[n:127.0.0.1:34915_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:34915/solr";,
[junit4] 2> "type":"NRT",
[junit4] 2> "waitForFinalState":"false"} current state version: 0
[junit4] 2> 614584 INFO
(OverseerStateUpdate-72124903234600963-127.0.0.1:34915_solr-n_0000000000)
[n:127.0.0.1:34915_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:34915/solr";,
[junit4] 2> "type":"NRT",
[junit4] 2> "waitForFinalState":"false"}
[junit4] 2> 614585 DEBUG
(OverseerStateUpdate-72124903234600963-127.0.0.1:34915_solr-n_0000000000)
[n:127.0.0.1:34915_solr ] o.a.s.c.o.SliceMutator Old Slice: shard1:{
[junit4] 2> "range":"80000000-7fffffff",
[junit4] 2> "state":"active",
[junit4] 2> "replicas":{}}
[junit4] 2> 614585 DEBUG
(OverseerStateUpdate-72124903234600963-127.0.0.1:34915_solr-n_0000000000)
[n:127.0.0.1:34915_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:34915/solr";,
[junit4] 2> "state":"down",
[junit4] 2> "node_name":null,
[junit4] 2> "type":"NRT"}}}
[junit4] 2> 614586 DEBUG
(OverseerStateUpdate-72124903234600963-127.0.0.1:34915_solr-n_0000000000)
[n:127.0.0.1:34915_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:34915/solr";,
[junit4] 2> "type":"NRT",
[junit4] 2> "waitForFinalState":"false"} current state version: 0
[junit4] 2> 614586 INFO
(OverseerStateUpdate-72124903234600963-127.0.0.1:34915_solr-n_0000000000)
[n:127.0.0.1:34915_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:34915/solr";,
[junit4] 2> "type":"NRT",
[junit4] 2> "waitForFinalState":"false"}
[junit4] 2> 614587 DEBUG
(OverseerStateUpdate-72124903234600963-127.0.0.1:34915_solr-n_0000000000)
[n:127.0.0.1:34915_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:34915/solr";,
[junit4] 2> "state":"down",
[junit4] 2> "node_name":null,
[junit4] 2> "type":"NRT"}}}
[junit4] 2> 614587 DEBUG
(OverseerStateUpdate-72124903234600963-127.0.0.1:34915_solr-n_0000000000)
[n:127.0.0.1:34915_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:34915/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:34915/solr";,
[junit4] 2> "state":"down",
[junit4] 2> "node_name":null,
[junit4] 2> "type":"NRT"}}}
[junit4] 2> 614687 DEBUG
(OverseerStateUpdate-72124903234600963-127.0.0.1:34915_solr-n_0000000000)
[n:127.0.0.1:34915_solr ] o.a.s.c.o.ZkStateWriter going to update_collection
/collections/testNodeAdded/state.json version: 0
[junit4] 2> 614793 INFO (qtp14049233-4239) [n:127.0.0.1:34915_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> 614793 INFO (qtp14049233-4240) [n:127.0.0.1:34915_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> 614794 INFO (qtp14049233-4239) [n:127.0.0.1:34915_solr ]
o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647
transient cores
[junit4] 2> 614796 DEBUG
(OverseerStateUpdate-72124903234600963-127.0.0.1:34915_solr-n_0000000000)
[n:127.0.0.1:34915_solr ] o.a.s.c.Overseer processMessage: queueSize: 2,
message = {
[junit4] 2> "core":"testNodeAdded_shard1_replica_n2",
[junit4] 2> "core_node_name":"core_node4",
[junit4] 2> "roles":null,
[junit4] 2> "base_url":"https://127.0.0.1:34915/solr";,
[junit4] 2> "node_name":"127.0.0.1:34915_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> 614796 DEBUG
(OverseerStateUpdate-72124903234600963-127.0.0.1:34915_solr-n_0000000000)
[n:127.0.0.1:34915_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:34915/solr";,
[junit4] 2> "node_name":"127.0.0.1:34915_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> 614797 DEBUG
(OverseerStateUpdate-72124903234600963-127.0.0.1:34915_solr-n_0000000000)
[n:127.0.0.1:34915_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:34915/solr","node_name":"127.0.0.1:34915_solr","state":"down","type":"NRT"}
[junit4] 2> 614797 DEBUG
(OverseerStateUpdate-72124903234600963-127.0.0.1:34915_solr-n_0000000000)
[n:127.0.0.1:34915_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:34915/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:34915/solr";,
[junit4] 2> "node_name":"127.0.0.1:34915_solr",
[junit4] 2> "state":"down",
[junit4] 2> "type":"NRT"}}}}}
[junit4] 2> 614797 DEBUG
(OverseerStateUpdate-72124903234600963-127.0.0.1:34915_solr-n_0000000000)
[n:127.0.0.1:34915_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:34915/solr";,
[junit4] 2> "node_name":"127.0.0.1:34915_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> 614797 DEBUG
(OverseerStateUpdate-72124903234600963-127.0.0.1:34915_solr-n_0000000000)
[n:127.0.0.1:34915_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:34915/solr";,
[junit4] 2> "node_name":"127.0.0.1:34915_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> 614797 DEBUG
(OverseerStateUpdate-72124903234600963-127.0.0.1:34915_solr-n_0000000000)
[n:127.0.0.1:34915_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:34915/solr","node_name":"127.0.0.1:34915_solr","state":"down","type":"NRT"}
[junit4] 2> 614797 DEBUG
(OverseerStateUpdate-72124903234600963-127.0.0.1:34915_solr-n_0000000000)
[n:127.0.0.1:34915_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:34915/solr";,
[junit4] 2> "node_name":"127.0.0.1:34915_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:34915/solr";,
[junit4] 2> "node_name":"127.0.0.1:34915_solr",
[junit4] 2> "state":"down",
[junit4] 2> "type":"NRT"}}}}}
[junit4] 2> 614898 DEBUG
(OverseerStateUpdate-72124903234600963-127.0.0.1:34915_solr-n_0000000000)
[n:127.0.0.1:34915_solr ] o.a.s.c.o.ZkStateWriter going to update_collection
/collections/testNodeAdded/state.json version: 1
[junit4] 2> 614898 INFO
(zkCallback-1001-thread-1-processing-n:127.0.0.1:34915_solr)
[n:127.0.0.1:34915_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> 614898 INFO
(zkCallback-1001-thread-2-processing-n:127.0.0.1:34915_solr)
[n:127.0.0.1:34915_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> 615472 DEBUG (ScheduledTrigger-1682-thread-2)
[n:127.0.0.1:34915_solr ] o.a.s.c.a.NodeAddedTrigger Running
NodeAddedTrigger node_added_trigger
[junit4] 2> 615472 DEBUG (ScheduledTrigger-1682-thread-2)
[n:127.0.0.1:34915_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 1
[junit4] 2> 615805 INFO (qtp14049233-4240) [n:127.0.0.1:34915_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> 615806 INFO (qtp14049233-4239) [n:127.0.0.1:34915_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> 615812 INFO (qtp14049233-4240) [n:127.0.0.1:34915_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> 615813 INFO (qtp14049233-4239) [n:127.0.0.1:34915_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> 615816 INFO (qtp14049233-4240) [n:127.0.0.1:34915_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> 615816 INFO (qtp14049233-4240) [n:127.0.0.1:34915_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> 615816 INFO (qtp14049233-4239) [n:127.0.0.1:34915_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> 615816 INFO (qtp14049233-4239) [n:127.0.0.1:34915_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> 615818 INFO (qtp14049233-4240) [n:127.0.0.1:34915_solr
c:testNodeAdded s:shard1 r:core_node4 x:testNodeAdded_shard1_replica_n2]
o.a.s.m.r.SolrJmxReporter JMX monitoring for
'solr_34915.solr.core.testNodeAdded.shard1.replica_n2' (registry
'solr.core.testNodeAdded.shard1.replica_n2') enabled at server:
com.sun.jmx.mbeanserver.JmxMBeanServer@12fe9f8
[junit4] 2> 615818 INFO (qtp14049233-4239) [n:127.0.0.1:34915_solr
c:testNodeAdded s:shard1 r:core_node3 x:testNodeAdded_shard1_replica_n1]
o.a.s.m.r.SolrJmxReporter JMX monitoring for
'solr_34915.solr.core.testNodeAdded.shard1.replica_n1' (registry
'solr.core.testNodeAdded.shard1.replica_n1') enabled at server:
com.sun.jmx.mbeanserver.JmxMBeanServer@12fe9f8
[junit4] 2> 615818 INFO (qtp14049233-4239) [n:127.0.0.1:34915_solr
c:testNodeAdded s:shard1 r:core_node3 x:testNodeAdded_shard1_replica_n1]
o.a.s.c.SolrCore solr.RecoveryStrategy.Builder
[junit4] 2> 615818 INFO (qtp14049233-4240) [n:127.0.0.1:34915_solr
c:testNodeAdded s:shard1 r:core_node4 x:testNodeAdded_shard1_replica_n2]
o.a.s.c.SolrCore solr.RecoveryStrategy.Builder
[junit4] 2> 615818 INFO (qtp14049233-4240) [n:127.0.0.1:34915_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/J0/temp/solr.cloud.autoscaling.ComputePlanActionTest_EBBA7F4A24CDA47F-001/tempDir-001/node1/testNodeAdded_shard1_replica_n2],
dataDir=[/home/jenkins/workspace/Lucene-Solr-7.x-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.autoscaling.ComputePlanActionTest_EBBA7F4A24CDA47F-001/tempDir-001/node1/./testNodeAdded_shard1_replica_n2/data/]
[junit4] 2> 615818 INFO (qtp14049233-4239) [n:127.0.0.1:34915_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/J0/temp/solr.cloud.autoscaling.ComputePlanActionTest_EBBA7F4A24CDA47F-001/tempDir-001/node1/testNodeAdded_shard1_replica_n1],
dataDir=[/home/jenkins/workspace/Lucene-Solr-7.x-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.autoscaling.ComputePlanActionTest_EBBA7F4A24CDA47F-001/tempDir-001/node1/./testNodeAdded_shard1_replica_n1/data/]
[junit4] 2> 615899 INFO (qtp14049233-4240) [n:127.0.0.1:34915_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> 615899 INFO (qtp14049233-4239) [n:127.0.0.1:34915_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> 615899 INFO (qtp14049233-4240) [n:127.0.0.1:34915_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> 615899 INFO (qtp14049233-4239) [n:127.0.0.1:34915_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> 615901 INFO (qtp14049233-4240) [n:127.0.0.1:34915_solr
c:testNodeAdded s:shard1 r:core_node4 x:testNodeAdded_shard1_replica_n2]
o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 615901 INFO (qtp14049233-4239) [n:127.0.0.1:34915_solr
c:testNodeAdded s:shard1 r:core_node3 x:testNodeAdded_shard1_replica_n1]
o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 615901 INFO (qtp14049233-4240) [n:127.0.0.1:34915_solr
c:testNodeAdded s:shard1 r:core_node4 x:testNodeAdded_shard1_replica_n2]
o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 615902 INFO (qtp14049233-4239) [n:127.0.0.1:34915_solr
c:testNodeAdded s:shard1 r:core_node3 x:testNodeAdded_shard1_replica_n1]
o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 615904 INFO (qtp14049233-4240) [n:127.0.0.1:34915_solr
c:testNodeAdded s:shard1 r:core_node4 x:testNodeAdded_shard1_replica_n2]
o.a.s.s.SolrIndexSearcher Opening
[Searcher@89cf88[testNodeAdded_shard1_replica_n2] main]
[junit4] 2> 615904 INFO (qtp14049233-4239) [n:127.0.0.1:34915_solr
c:testNodeAdded s:shard1 r:core_node3 x:testNodeAdded_shard1_replica_n1]
o.a.s.s.SolrIndexSearcher Opening
[Searcher@1e9619c[testNodeAdded_shard1_replica_n1] main]
[junit4] 2> 615905 INFO (qtp14049233-4240) [n:127.0.0.1:34915_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> 615905 INFO (qtp14049233-4239) [n:127.0.0.1:34915_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> 615906 INFO (qtp14049233-4240) [n:127.0.0.1:34915_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> 615906 INFO (qtp14049233-4239) [n:127.0.0.1:34915_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> 615907 INFO (qtp14049233-4240) [n:127.0.0.1:34915_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> 615907 INFO (qtp14049233-4239) [n:127.0.0.1:34915_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> 615908 INFO
(searcherExecutor-1687-thread-1-processing-n:127.0.0.1:34915_solr
x:testNodeAdded_shard1_replica_n2 s:shard1 c:testNodeAdded r:core_node4)
[n:127.0.0.1:34915_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@89cf88[testNodeAdded_shard1_replica_n2]
main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 615908 INFO
(searcherExecutor-1688-thread-1-processing-n:127.0.0.1:34915_solr
x:testNodeAdded_shard1_replica_n1 s:shard1 c:testNodeAdded r:core_node3)
[n:127.0.0.1:34915_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@1e9619c[testNodeAdded_shard1_replica_n1]
main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 615908 INFO (qtp14049233-4240) [n:127.0.0.1:34915_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 1592015085527629824
[junit4] 2> 615909 INFO (qtp14049233-4239) [n:127.0.0.1:34915_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 1592015085528678400
[junit4] 2> 615913 INFO (qtp14049233-4239) [n:127.0.0.1:34915_solr
c:testNodeAdded s:shard1 r:core_node3 x:testNodeAdded_shard1_replica_n1]
o.a.s.c.ZkShardTerms Failed to save terms, version is not match, retrying
[junit4] 2> 615916 INFO (qtp14049233-4239) [n:127.0.0.1:34915_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> 615916 INFO (qtp14049233-4239) [n:127.0.0.1:34915_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> 615916 INFO (qtp14049233-4239) [n:127.0.0.1:34915_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:34915/solr/testNodeAdded_shard1_replica_n1/
[junit4] 2> 615916 DEBUG
(OverseerStateUpdate-72124903234600963-127.0.0.1:34915_solr-n_0000000000)
[n:127.0.0.1:34915_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> 615916 INFO (qtp14049233-4239) [n:127.0.0.1:34915_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:34915/solr START
replicas=[https://127.0.0.1:34915/solr/testNodeAdded_shard1_replica_n2/]
nUpdates=100
[junit4] 2> 615921 INFO (qtp14049233-4209) [n:127.0.0.1:34915_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> 616017 DEBUG
(OverseerStateUpdate-72124903234600963-127.0.0.1:34915_solr-n_0000000000)
[n:127.0.0.1:34915_solr ] o.a.s.c.o.ZkStateWriter going to update_collection
/collections/testNodeAdded/state.json version: 2
[junit4] 2> 616017 INFO
(zkCallback-1001-thread-3-processing-n:127.0.0.1:34915_solr)
[n:127.0.0.1:34915_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> 616017 INFO
(zkCallback-1001-thread-2-processing-n:127.0.0.1:34915_solr)
[n:127.0.0.1:34915_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> 616217 INFO (qtp14049233-4239) [n:127.0.0.1:34915_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:34915/solr DONE. We have no versions. sync failed.
[junit4] 2> 616217 INFO (qtp14049233-4239) [n:127.0.0.1:34915_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> 616217 INFO (qtp14049233-4239) [n:127.0.0.1:34915_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> 616217 INFO (qtp14049233-4239) [n:127.0.0.1:34915_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> 616219 INFO (qtp14049233-4239) [n:127.0.0.1:34915_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:34915/solr/testNodeAdded_shard1_replica_n1/ shard1
[junit4] 2> 616220 DEBUG
(OverseerStateUpdate-72124903234600963-127.0.0.1:34915_solr-n_0000000000)
[n:127.0.0.1:34915_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:34915/solr";,
[junit4] 2> "core":"testNodeAdded_shard1_replica_n1",
[junit4] 2> "state":"active"} current state version: 0
[junit4] 2> 616320 DEBUG
(OverseerStateUpdate-72124903234600963-127.0.0.1:34915_solr-n_0000000000)
[n:127.0.0.1:34915_solr ] o.a.s.c.o.ZkStateWriter going to update_collection
/collections/testNodeAdded/state.json version: 3
[junit4] 2> 616321 INFO
(zkCallback-1001-thread-3-processing-n:127.0.0.1:34915_solr)
[n:127.0.0.1:34915_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> 616321 INFO
(zkCallback-1001-thread-2-processing-n:127.0.0.1:34915_solr)
[n:127.0.0.1:34915_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> 616370 INFO (qtp14049233-4239) [n:127.0.0.1:34915_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> 616372 DEBUG
(OverseerStateUpdate-72124903234600963-127.0.0.1:34915_solr-n_0000000000)
[n:127.0.0.1:34915_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:34915/solr";,
[junit4] 2> "node_name":"127.0.0.1:34915_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> 616372 DEBUG
(OverseerStateUpdate-72124903234600963-127.0.0.1:34915_solr-n_0000000000)
[n:127.0.0.1:34915_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:34915/solr";,
[junit4] 2> "node_name":"127.0.0.1:34915_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> 616372 DEBUG
(OverseerStateUpdate-72124903234600963-127.0.0.1:34915_solr-n_0000000000)
[n:127.0.0.1:34915_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:34915/solr","node_name":"127.0.0.1:34915_solr","state":"active","type":"NRT","leader":"true"}
[junit4] 2> 616372 DEBUG
(OverseerStateUpdate-72124903234600963-127.0.0.1:34915_solr-n_0000000000)
[n:127.0.0.1:34915_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:34915/solr";,
[junit4] 2> "node_name":"127.0.0.1:34915_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:34915/solr";,
[junit4] 2> "node_name":"127.0.0.1:34915_solr",
[junit4] 2> "state":"down",
[junit4] 2> "type":"NRT"}}}}}
[junit4] 2> 616447 INFO (qtp14049233-4239) [n:127.0.0.1:34915_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=1654
[junit4] 2> 616472 DEBUG (ScheduledTrigger-1682-thread-2)
[n:127.0.0.1:34915_solr ] o.a.s.c.a.NodeAddedTrigger Running
NodeAddedTrigger node_added_trigger
[junit4] 2> 616472 DEBUG (ScheduledTrigger-1682-thread-2)
[n:127.0.0.1:34915_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 1
[junit4] 2> 616473 DEBUG
(OverseerStateUpdate-72124903234600963-127.0.0.1:34915_solr-n_0000000000)
[n:127.0.0.1:34915_solr ] o.a.s.c.o.ZkStateWriter going to update_collection
/collections/testNodeAdded/state.json version: 4
[junit4] 2> 616473 INFO
(zkCallback-1001-thread-3-processing-n:127.0.0.1:34915_solr)
[n:127.0.0.1:34915_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> 616473 INFO
(zkCallback-1001-thread-2-processing-n:127.0.0.1:34915_solr)
[n:127.0.0.1:34915_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> 616917 DEBUG
(OverseerStateUpdate-72124903234600963-127.0.0.1:34915_solr-n_0000000000)
[n:127.0.0.1:34915_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:34915/solr";,
[junit4] 2> "node_name":"127.0.0.1:34915_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> 616917 DEBUG
(OverseerStateUpdate-72124903234600963-127.0.0.1:34915_solr-n_0000000000)
[n:127.0.0.1:34915_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:34915/solr";,
[junit4] 2> "node_name":"127.0.0.1:34915_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> 616917 DEBUG
(OverseerStateUpdate-72124903234600963-127.0.0.1:34915_solr-n_0000000000)
[n:127.0.0.1:34915_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:34915/solr","node_name":"127.0.0.1:34915_solr","state":"active","type":"NRT"}
[junit4] 2> 616917 DEBUG
(OverseerStateUpdate-72124903234600963-127.0.0.1:34915_solr-n_0000000000)
[n:127.0.0.1:34915_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:34915/solr";,
[junit4] 2> "node_name":"127.0.0.1:34915_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:34915/solr";,
[junit4] 2> "node_name":"127.0.0.1:34915_solr",
[junit4] 2> "state":"active",
[junit4] 2> "type":"NRT"}}}}}
[junit4] 2> 616958 INFO (qtp14049233-4240) [n:127.0.0.1:34915_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=2165
[junit4] 2> 616962 INFO (qtp14049233-4207) [n:127.0.0.1:34915_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> 617018 DEBUG
(OverseerStateUpdate-72124903234600963-127.0.0.1:34915_solr-n_0000000000)
[n:127.0.0.1:34915_solr ] o.a.s.c.o.ZkStateWriter going to update_collection
/collections/testNodeAdded/state.json version: 5
[junit4] 2> 617018 INFO
(zkCallback-1001-thread-2-processing-n:127.0.0.1:34915_solr)
[n:127.0.0.1:34915_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> 617018 INFO
(zkCallback-1001-thread-3-processing-n:127.0.0.1:34915_solr)
[n:127.0.0.1:34915_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> 617472 DEBUG (ScheduledTrigger-1682-thread-2)
[n:127.0.0.1:34915_solr ] o.a.s.c.a.NodeAddedTrigger Running
NodeAddedTrigger node_added_trigger
[junit4] 2> 617473 DEBUG (ScheduledTrigger-1682-thread-2)
[n:127.0.0.1:34915_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 1
[junit4] 2> 617962 INFO (qtp14049233-4207) [n:127.0.0.1:34915_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=3491
[junit4] 2> 617968 INFO (qtp14049233-4208) [n:127.0.0.1:34915_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> 617972 INFO (qtp14049233-4240) [n:127.0.0.1:34915_solr ]
o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics
params={prefix=CONTAINER.fs.usableSpace,CORE.coreName&wt=javabin&version=2&group=solr.node,solr.core}
status=0 QTime=1
[junit4] 2> 617973 DEBUG (qtp14049233-4202) [n:127.0.0.1:34915_solr ]
o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
[junit4] 2> 617974 INFO (qtp14049233-4202) [n:127.0.0.1:34915_solr ]
o.a.s.s.HttpSolrCall [admin] webapp=null path=/cluster/autoscaling
params={wt=javabin&version=2} status=0 QTime=8
[junit4] 2> 617974 DEBUG
(zkCallback-1001-thread-3-processing-n:127.0.0.1:34915_solr)
[n:127.0.0.1:34915_solr ] o.a.s.c.a.OverseerTriggerThread Refreshing
/autoscaling.json with znode version 7
[junit4] 2> 617975 DEBUG
(zkCallback-1001-thread-3-processing-n:127.0.0.1:34915_solr)
[n:127.0.0.1:34915_solr ] o.a.s.c.a.NodeAddedTrigger Initial livenodes:
[127.0.0.1:34915_solr]
[junit4] 2> 617975 DEBUG
(zkCallback-1001-thread-3-processing-n:127.0.0.1:34915_solr)
[n:127.0.0.1:34915_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> 617975 DEBUG
(OverseerAutoScalingTriggerThread-72124903234600963-127.0.0.1:34915_solr-n_0000000000)
[n:127.0.0.1:34915_solr ] o.a.s.c.a.OverseerTriggerThread Processed trigger
updates upto znodeVersion 7
[junit4] 2> 617975 DEBUG
(OverseerAutoScalingTriggerThread-72124903234600963-127.0.0.1:34915_solr-n_0000000000)
[n:127.0.0.1:34915_solr ] o.a.s.c.a.OverseerTriggerThread -- clean old
nodeLost markers
[junit4] 2> 617976 DEBUG
(OverseerAutoScalingTriggerThread-72124903234600963-127.0.0.1:34915_solr-n_0000000000)
[n:127.0.0.1:34915_solr ] o.a.s.c.a.OverseerTriggerThread Current
znodeVersion 7, lastZnodeVersion 7
[junit4] 2> 617977 INFO
(TEST-ComputePlanActionTest.testNodeAdded-seed#[EBBA7F4A24CDA47F]) [ ]
o.e.j.s.Server jetty-9.4.8.v20171121, build timestamp:
2017-11-21T10:27:37-11:00, git hash: 82b8fb23f757335bb3329d540ce37a2a2615f0a8
[junit4] 2> 617977 INFO
(TEST-ComputePlanActionTest.testNodeAdded-seed#[EBBA7F4A24CDA47F]) [ ]
o.e.j.s.session DefaultSessionIdManager workerName=node0
[junit4] 2> 617977 INFO
(TEST-ComputePlanActionTest.testNodeAdded-seed#[EBBA7F4A24CDA47F]) [ ]
o.e.j.s.session No SessionScavenger set, using defaults
[junit4] 2> 617977 INFO
(TEST-ComputePlanActionTest.testNodeAdded-seed#[EBBA7F4A24CDA47F]) [ ]
o.e.j.s.session Scavenging every 660000ms
[junit4] 2> 617978 INFO
(TEST-ComputePlanActionTest.testNodeAdded-seed#[EBBA7F4A24CDA47F]) [ ]
o.e.j.s.h.ContextHandler Started
o.e.j.s.ServletContextHandler@682fd3{/solr,null,AVAILABLE}
[junit4] 2> 617978 INFO
(TEST-ComputePlanActionTest.testNodeAdded-seed#[EBBA7F4A24CDA47F]) [ ]
o.e.j.s.AbstractConnector Started ServerConnector@1b352fc{SSL,[ssl,
http/1.1]}{127.0.0.1:39019}
[junit4] 2> 617978 INFO
(TEST-ComputePlanActionTest.testNodeAdded-seed#[EBBA7F4A24CDA47F]) [ ]
o.e.j.s.Server Started @619297ms
[junit4] 2> 617978 INFO
(TEST-ComputePlanActionTest.testNodeAdded-seed#[EBBA7F4A24CDA47F]) [ ]
o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr,
hostPort=39019}
[junit4] 2> 617979 ERROR
(TEST-ComputePlanActionTest.testNodeAdded-seed#[EBBA7F4A24CDA47F]) [ ]
o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be
missing or incomplete.
[junit4] 2> 617979 INFO
(TEST-ComputePlanActionTest.testNodeAdded-seed#[EBBA7F4A24CDA47F]) [ ]
o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr™ version
7.3.0
[junit4] 2> 617979 INFO
(TEST-ComputePlanActionTest.testNodeAdded-seed#[EBBA7F4A24CDA47F]) [ ]
o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 617979 INFO
(TEST-ComputePlanActionTest.testNodeAdded-seed#[EBBA7F4A24CDA47F]) [ ]
o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 617979 INFO
(TEST-ComputePlanActionTest.testNodeAdded-seed#[EBBA7F4A24CDA47F]) [ ]
o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time:
2018-02-10T11:58:20.470Z
[junit4] 2> 617981 INFO (zkConnectionManagerCallback-1013-thread-1) [
] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 617982 INFO
(TEST-ComputePlanActionTest.testNodeAdded-seed#[EBBA7F4A24CDA47F]) [ ]
o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 617992 INFO
(TEST-ComputePlanActionTest.testNodeAdded-seed#[EBBA7F4A24CDA47F]) [ ]
o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:44701/solr
[junit4] 2> 617994 INFO (zkConnectionManagerCallback-1017-thread-1) [
] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 617996 INFO
(zkConnectionManagerCallback-1019-thread-1-processing-n:127.0.0.1:39019_solr)
[n:127.0.0.1:39019_solr ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 618001 INFO
(TEST-ComputePlanActionTest.testNodeAdded-seed#[EBBA7F4A24CDA47F])
[n:127.0.0.1:39019_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (0) -> (1)
[junit4] 2> 618002 INFO
(TEST-ComputePlanActionTest.testNodeAdded-seed#[EBBA7F4A24CDA47F])
[n:127.0.0.1:39019_solr ] o.a.s.c.Overseer Overseer (id=null) closing
[junit4] 2> 618004 INFO
(TEST-ComputePlanActionTest.testNodeAdded-seed#[EBBA7F4A24CDA47F])
[n:127.0.0.1:39019_solr ] o.a.s.c.ZkController Register node as live in
ZooKeeper:/live_nodes/127.0.0.1:39019_solr
[junit4] 2> 618005 DEBUG
(OverseerStateUpdate-72124903234600963-127.0.0.1:34915_solr-n_0000000000)
[n:127.0.0.1:34915_solr ] o.a.s.c.Overseer processMessage: queueSize: 1,
message = {
[junit4] 2> "operation":"downnode",
[junit4] 2> "node_name":"127.0.0.1:39019_solr"} current state version: 0
[junit4] 2> 618005 DEBUG
(OverseerStateUpdate-72124903234600963-127.0.0.1:34915_solr-n_0000000000)
[n:127.0.0.1:34915_solr ] o.a.s.c.o.NodeMutator DownNode state invoked for
node: 127.0.0.1:39019_solr
[junit4] 2> 618005 INFO
(zkCallback-1001-thread-3-processing-n:127.0.0.1:34915_solr)
[n:127.0.0.1:34915_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (1) -> (2)
[junit4] 2> 618005 INFO (zkCallback-1009-thread-2) [ ]
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
[junit4] 2> 618005 INFO (zkCallback-1009-thread-1) [ ]
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
[junit4] 2> 618006 INFO
(zkCallback-1018-thread-1-processing-n:127.0.0.1:39019_solr)
[n:127.0.0.1:39019_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (1) -> (2)
[junit4] 2> 618177 INFO
(TEST-ComputePlanActionTest.testNodeAdded-seed#[EBBA7F4A24CDA47F])
[n:127.0.0.1:39019_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for
'solr_39019.solr.node' (registry 'solr.node') enabled at server:
com.sun.jmx.mbeanserver.JmxMBeanServer@12fe9f8
[junit4] 2> 618188 INFO
(TEST-ComputePlanActionTest.testNodeAdded-seed#[EBBA7F4A24CDA47F])
[n:127.0.0.1:39019_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for
'solr_39019.solr.jvm' (registry 'solr.jvm') enabled at server:
com.sun.jmx.mbeanserver.JmxMBeanServer@12fe9f8
[junit4] 2> 618189 INFO
(TEST-ComputePlanActionTest.testNodeAdded-seed#[EBBA7F4A24CDA47F])
[n:127.0.0.1:39019_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for
'solr_39019.solr.jetty' (registry 'solr.jetty') enabled at server:
com.sun.jmx.mbeanserver.JmxMBeanServer@12fe9f8
[junit4] 2> 618190 INFO
(TEST-ComputePlanActionTest.testNodeAdded-seed#[EBBA7F4A24CDA47F])
[n:127.0.0.1:39019_solr ] o.a.s.c.CorePropertiesLocator Found 0 core
definitions underneath
/home/jenkins/workspace/Lucene-Solr-7.x-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.autoscaling.ComputePlanActionTest_EBBA7F4A24CDA47F-001/tempDir-001/node2/.
[junit4] 2> 618473 DEBUG (ScheduledTrigger-1682-thread-2)
[n:127.0.0.1:34915_solr ] o.a.s.c.a.NodeAddedTrigger Running
NodeAddedTrigger node_added_trigger
[junit4] 2> 618473 DEBUG (ScheduledTrigger-1682-thread-2)
[n:127.0.0.1:34915_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 2
[junit4] 2> 618473 DEBUG (ScheduledTrigger-1682-thread-2)
[n:127.0.0.1:34915_solr ] o.a.s.c.a.NodeAddedTrigger Tracking new node:
127.0.0.1:39019_solr at time 1027061401840877
[junit4] 2> 618478 INFO
(OverseerCollectionConfigSetProcessor-72124903234600963-127.0.0.1:34915_solr-n_0000000000)
[n:127.0.0.1:34915_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> 619474 DEBUG (ScheduledTrigger-1682-thread-2)
[n:127.0.0.1:34915_solr ] o.a.s.c.a.NodeAddedTrigger Running
NodeAddedTrigger node_added_trigger
[junit4] 2> 619474 DEBUG (ScheduledTrigger-1682-thread-2)
[n:127.0.0.1:34915_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 2
[junit4] 2> 619474 DEBUG (ScheduledTrigger-1682-thread-2)
[n:127.0.0.1:34915_solr ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger
node_added_trigger firing registered processor for nodes:
[127.0.0.1:39019_solr] added at times [1027061401840877], now=1027062403035688
[junit4] 2> 619474 DEBUG (ScheduledTrigger-1682-thread-2)
[n:127.0.0.1:34915_solr ] o.a.s.c.a.ScheduledTriggers ++++++++ Cooldown
inactive - processing event: {
[junit4] 2> "id":"3a61b5e04ecedT78agd439mwxs7djifq7sqiodg",
[junit4] 2> "source":"node_added_trigger",
[junit4] 2> "eventTime":1027061401840877,
[junit4] 2> "eventType":"NODEADDED",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[1027061401840877],
[junit4] 2> "nodeNames":["127.0.0.1:39019_solr"]}}
[junit4] 2> 619475 DEBUG (ScheduledTrigger-1682-thread-2)
[n:127.0.0.1:34915_solr ] o.a.s.c.a.ScheduledTriggers Pausing all triggers:
[node_added_trigger]
[junit4] 2> 619476 INFO (ScheduledTrigger-1682-thread-2)
[n:127.0.0.1:34915_solr ] o.a.s.c.a.SystemLogListener Collection .system
does not exist, disabling logging.
[junit4] 2> 619476 DEBUG
(AutoscalingActionExecutor-1683-thread-1-processing-n:127.0.0.1:34915_solr)
[n:127.0.0.1:34915_solr ] o.a.s.c.a.ScheduledTriggers -- processing actions
for {
[junit4] 2> "id":"3a61b5e04ecedT78agd439mwxs7djifq7sqiodg",
[junit4] 2> "source":"node_added_trigger",
[junit4] 2> "eventTime":1027061401840877,
[junit4] 2> "eventType":"NODEADDED",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[1027061401840877],
[junit4] 2> "_enqueue_time_":1027062403753183,
[junit4] 2> "nodeNames":["127.0.0.1:39019_solr"]}}
[junit4] 2> 619476 DEBUG
(AutoscalingActionExecutor-1683-thread-1-processing-n:127.0.0.1:34915_solr)
[n:127.0.0.1:34915_solr ] o.a.s.c.a.ComputePlanAction -- processing event: {
[junit4] 2> "id":"3a61b5e04ecedT78agd439mwxs7djifq7sqiodg",
[junit4] 2> "source":"node_added_trigger",
[junit4] 2> "eventTime":1027061401840877,
[junit4] 2> "eventType":"NODEADDED",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[1027061401840877],
[junit4] 2> "_enqueue_time_":1027062403753183,
[junit4] 2> "nodeNames":["127.0.0.1:39019_solr"]}} with context
properties: {BEFORE_ACTION=[compute_plan]}
[junit4] 2> 619479 INFO (qtp14049233-4208) [n:127.0.0.1:34915_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> 619482 INFO (qtp14049233-4202) [n:127.0.0.1:34915_solr ]
o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics
params={prefix=CONTAINER.fs.usableSpace,CORE.coreName&wt=javabin&version=2&group=solr.node,solr.core}
status=0 QTime=1
[junit4] 2> 619564 INFO (qtp22235156-4265) [n:127.0.0.1:39019_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> 619565 INFO
(AutoscalingActionExecutor-1683-thread-1-processing-n:127.0.0.1:34915_solr)
[n:127.0.0.1:34915_solr ] o.a.s.c.a.ComputePlanAction Computed Plan:
action=MOVEREPLICA&collection=testNodeAdded&targetNode=127.0.0.1:39019_solr&inPlaceMove=true&replica=core_node3
[junit4] 2> 619566 INFO
(AutoscalingActionExecutor-1683-thread-1-processing-n:127.0.0.1:34915_solr)
[n:127.0.0.1:34915_solr ] o.a.s.c.s.c.a.PolicyHelper returnSession,
curr-time 1027062494 sessionWrapper.createTime 1027062493489752,
this.sessionWrapper.createTime 1027062493489752
[junit4] 2> 619566 DEBUG
(TEST-ComputePlanActionTest.testNodeAdded-seed#[EBBA7F4A24CDA47F]) [ ]
o.a.s.c.a.ComputePlanActionTest -------------_ FINAL STATE --------------
[junit4] 2> 619567 DEBUG
(AutoscalingActionExecutor-1683-thread-1-processing-n:127.0.0.1:34915_solr)
[n:127.0.0.1:34915_solr ] o.a.s.c.a.ScheduledTriggers Resuming trigger:
node_added_trigger after 5000ms
[junit4] 2> 619567 DEBUG
(AutoscalingActionExecutor-1683-thread-1-processing-n:127.0.0.1:34915_solr)
[n:127.0.0.1:34915_solr ] o.a.s.c.a.ScheduledTriggers -- processing took 90
ms for event id=3a61b5e04ecedT78agd439mwxs7djifq7sqiodg
[junit4] 2> 619569 INFO (qtp14049233-4208) [n:127.0.0.1:34915_solr ]
o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics
params={prefix=CONTAINER.fs.usableSpace,CORE.coreName&wt=javabin&version=2&group=solr.node,solr.core}
status=0 QTime=1
[junit4] 2> 619570 DEBUG
(TEST-ComputePlanActionTest.testNodeAdded-seed#[EBBA7F4A24CDA47F]) [ ]
o.a.s.c.a.ComputePlanActionTest * Node values: 127.0.0.1:34915_solr
[junit4] 2> {
[junit4] 2> "node":"127.0.0.1:34915_solr",
[junit4] 2> "cores":2,
[junit4] 2> "port":"34915",
[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":211.65549850463867}
[junit4] 2> 619572 INFO (qtp22235156-4267) [n:127.0.0.1:39019_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> 619573 DEBUG
(TEST-ComputePlanActionTest.testNodeAdded-seed#[EBBA7F4A24CDA47F]) [ ]
o.a.s.c.a.ComputePlanActionTest * Node values: 127.0.0.1:39019_solr
[junit4] 2> {
[junit4] 2> "node":"127.0.0.1:39019_solr",
[junit4] 2> "cores":0,
[junit4] 2> "port":"39019",
[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":211.65549850463867}
[junit4] 2> 619573 DEBUG
(TEST-ComputePlanActionTest.testNodeAdded-seed#[EBBA7F4A24CDA47F]) [ ]
o.a.s.c.a.ComputePlanActionTest * Live nodes: [127.0.0.1:34915_solr,
127.0.0.1:39019_solr]
[junit4] 2> 619574 DEBUG
(TEST-ComputePlanActionTest.testNodeAdded-seed#[EBBA7F4A24CDA47F]) [ ]
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:34915/solr";,
[junit4] 2> "node_name":"127.0.0.1:34915_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:34915/solr";,
[junit4] 2> "node_name":"127.0.0.1:34915_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> 619574 INFO
(TEST-ComputePlanActionTest.testNodeAdded-seed#[EBBA7F4A24CDA47F]) [ ]
o.a.s.SolrTestCaseJ4 ###Ending testNodeAdded
[junit4] 2> 619591 INFO
(TEST-ComputePlanActionTest.testNodeLost-seed#[EBBA7F4A24CDA47F]) [ ]
o.a.s.SolrTestCaseJ4 ###Starting testNodeLost
[junit4] 2> 619592 DEBUG
(zkCallback-1001-thread-3-processing-n:127.0.0.1:34915_solr)
[n:127.0.0.1:34915_solr ] o.a.s.c.a.OverseerTriggerThread Refreshing
/autoscaling.json with znode version 8
[junit4] 2> 619592 DEBUG
(OverseerAutoScalingTriggerThread-72124903234600963-127.0.0.1:34915_solr-n_0000000000)
[n:127.0.0.1:34915_solr ] o.a.s.c.a.OverseerTriggerThread Processed trigger
updates upto znodeVersion 8
[junit4] 2> 619593 INFO
(TEST-ComputePlanActionTest.testNodeLost-seed#[EBBA7F4A24CDA47F]) [ ] o.e.j
[...truncated too long message...]
2>
[junit4] 2> Maximum concurrent data watches above limit:
[junit4] 2>
[junit4] 2> 38 /solr/collections/rulesColl/state.json
[junit4] 2> 16 /solr/collections/modifyColl/state.json
[junit4] 2> 13 /solr/clusterstate.json
[junit4] 2> 12 /solr/collections/hostFragment/state.json
[junit4] 2> 6 /solr/collections/portRuleColl2/state.json
[junit4] 2> 6 /solr/collections/portRuleColl/state.json
[junit4] 2> 2
/solr/overseer_elect/election/72124988495953930-127.0.0.1:36003_solr-n_0000000002
[junit4] 2> 2
/solr/overseer_elect/election/72124988495953933-127.0.0.1:37007_solr-n_0000000000
[junit4] 2>
[junit4] 2> Maximum concurrent children watches above limit:
[junit4] 2>
[junit4] 2> 46 /solr/collections
[junit4] 2> 13 /solr/live_nodes
[junit4] 2>
[junit4] 2> 1976592 INFO (SUITE-RulesTest-seed#[EBBA7F4A24CDA47F]-worker)
[ ] o.a.s.SolrTestCaseJ4
------------------------------------------------------- Done waiting for
tracked resources to be released
[junit4] 2> Feb 10, 2018 12:20:59 PM
com.carrotsearch.randomizedtesting.ThreadLeakControl checkThreadLeaks
[junit4] 2> WARNING: Will linger awaiting termination of 1 leaked
thread(s).
[junit4] 2> Feb 10, 2018 12:21:19 PM
com.carrotsearch.randomizedtesting.ThreadLeakControl checkThreadLeaks
[junit4] 2> SEVERE: 1 thread leaked from SUITE scope at
org.apache.solr.cloud.rule.RulesTest:
[junit4] 2> 1) Thread[id=16595, name=qtp27345429-16595,
state=TIMED_WAITING, group=TGRP-RulesTest]
[junit4] 2> at sun.misc.Unsafe.park(Native Method)
[junit4] 2> at
java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215)
[junit4] 2> at
java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2163)
[junit4] 2> at
org.eclipse.jetty.util.thread.ReservedThreadExecutor$ReservedThread.reservedWait(ReservedThreadExecutor.java:308)
[junit4] 2> at
org.eclipse.jetty.util.thread.ReservedThreadExecutor$ReservedThread.run(ReservedThreadExecutor.java:373)
[junit4] 2> at
org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:708)
[junit4] 2> at
org.eclipse.jetty.util.thread.QueuedThreadPool$2.run(QueuedThreadPool.java:626)
[junit4] 2> at java.lang.Thread.run(Thread.java:748)
[junit4] 2> Feb 10, 2018 12:21:19 PM
com.carrotsearch.randomizedtesting.ThreadLeakControl tryToInterruptAll
[junit4] 2> INFO: Starting to interrupt leaked threads:
[junit4] 2> 1) Thread[id=16595, name=qtp27345429-16595,
state=TIMED_WAITING, group=TGRP-RulesTest]
[junit4] 2> Feb 10, 2018 12:21:22 PM
com.carrotsearch.randomizedtesting.ThreadLeakControl tryToInterruptAll
[junit4] 2> SEVERE: There are still zombie threads that couldn't be
terminated:
[junit4] 2> 1) Thread[id=16595, name=qtp27345429-16595,
state=TIMED_WAITING, group=TGRP-RulesTest]
[junit4] 2> at sun.misc.Unsafe.park(Native Method)
[junit4] 2> at
java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215)
[junit4] 2> at
java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2163)
[junit4] 2> at
org.eclipse.jetty.util.thread.ReservedThreadExecutor$ReservedThread.reservedWait(ReservedThreadExecutor.java:308)
[junit4] 2> at
org.eclipse.jetty.util.thread.ReservedThreadExecutor$ReservedThread.run(ReservedThreadExecutor.java:373)
[junit4] 2> at
org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:708)
[junit4] 2> at
org.eclipse.jetty.util.thread.QueuedThreadPool$2.run(QueuedThreadPool.java:626)
[junit4] 2> at java.lang.Thread.run(Thread.java:748)
[junit4] 2> NOTE: test params are: codec=Asserting(Lucene70): {},
docValues:{}, maxPointsInLeafNode=1770, maxMBSortInHeap=6.82594563519436,
sim=RandomSimilarity(queryNorm=false): {}, locale=th, timezone=CTT
[junit4] 2> NOTE: Linux 4.13.0-32-generic i386/Oracle Corporation
1.8.0_162 (32-bit)/cpus=8,threads=2,free=281410632,total=536870912
[junit4] 2> NOTE: All tests run in this JVM: [SuggesterTest,
TestSchemaVersionResource, QueryParsingTest, TestRebalanceLeaders,
FastVectorHighlighterTest, AlternateDirectoryTest, TestUninvertingReader,
DeleteNodeTest, TestReplicationHandler, TestQueryUtils,
DocValuesNotIndexedTest, UninvertDocValuesMergePolicyTest, ZkStateWriterTest,
MoveReplicaHDFSFailoverTest, TestPerFieldSimilarity, TestCorePropertiesReload,
TestSearchPerf, TestImpersonationWithHadoopAuth, SyncSliceTest,
DeleteStatusTest, CdcrVersionReplicationTest, DistributedDebugComponentTest,
MetricTriggerTest, TermsComponentTest, TestReversedWildcardFilterFactory,
SolrCoreTest, DistributedMLTComponentTest, TestEmbeddedSolrServerAdminHandler,
TestSurroundQueryParser, TestPullReplicaErrorHandling, TestHashQParserPlugin,
TestPolicyCloud, SchemaVersionSpecificBehaviorTest, JvmMetricsTest,
PropertiesRequestHandlerTest, HdfsRestartWhileUpdatingTest,
SolrShardReporterTest, OverseerTest, QueryEqualityTest, TestTrie,
TestUseDocValuesAsStored, SpellCheckCollatorWithCollapseTest, UpdateLogTest,
TestConfigSetImmutable, HttpSolrCallGetCoreTest, TestJettySolrRunner,
CdcrUpdateLogTest, PolyFieldTest, TestCharFilters,
TestExclusionRuleCollectionAccess, DirectSolrConnectionTest,
TestDeleteCollectionOnDownNodes, OverseerRolesTest, HighlighterMaxOffsetTest,
BaseCdcrDistributedZkTest, TestMacroExpander, SolrInfoBeanTest, TestDistribIDF,
BlockJoinFacetSimpleTest, TestOnReconnectListenerSupport,
AsyncCallRequestStatusResponseTest,
ClassificationUpdateProcessorIntegrationTest,
TestCollectionsAPIViaSolrCloudCluster, TestManagedStopFilterFactory,
TestFunctionQuery, SolrIndexMetricsTest, StressHdfsTest, TestSimpleTextCodec,
IndexSchemaTest, QueryElevationComponentTest, FileUtilsTest,
LoggingHandlerTest, FieldMutatingUpdateProcessorTest, TestRecovery,
DirectoryFactoryTest, TestSystemCollAutoCreate, TestFuzzyAnalyzedSuggestions,
StatsReloadRaceTest, TestDynamicFieldCollectionResource,
DistributedIntervalFacetingTest, ConcurrentDeleteAndCreateCollectionTest,
TestNumericRangeQuery64, TestTrieFacet, UUIDUpdateProcessorFallbackTest,
ShardRoutingCustomTest, LeaderFailoverAfterPartitionTest, JsonLoaderTest,
TestMinMaxOnMultiValuedField, TestConfigsApi, TestJsonRequest, ShardSplitTest,
TestSubQueryTransformerDistrib, TestNoOpRegenerator, TestFieldSortValues,
ZkControllerTest, TestBM25SimilarityFactory, SearchHandlerTest,
TestSolrIndexConfig, TestCollationFieldDocValues, TestSmileRequest,
BitVectorTest, SOLR749Test, TestCloudSearcherWarming,
TestClassicSimilarityFactory, TestReqParamsAPI, TestSolrCLIRunExample,
TestRTGBase, ReplaceNodeNoTargetTest, HLLSerializationTest, TestReloadDeadlock,
TestTolerantUpdateProcessorRandomCloud, PKIAuthenticationIntegrationTest,
HdfsDirectoryTest, TestFastLRUCache, TestRuleBasedAuthorizationPlugin,
TestReload, SolrMetricManagerTest, TestNestedDocsSort, TestSolrJ, TestZkChroot,
TestPayloadScoreQParserPlugin, TestLegacyFieldCache, SliceStateTest,
CollectionStateFormat2Test, RulesTest]
[junit4] 2> NOTE: reproduce with: ant test -Dtestcase=RulesTest
-Dtests.seed=EBBA7F4A24CDA47F -Dtests.multiplier=3 -Dtests.slow=true
-Dtests.locale=th -Dtests.timezone=CTT -Dtests.asserts=true
-Dtests.file.encoding=UTF-8
[junit4] ERROR 0.00s J1 | RulesTest (suite) <<<
[junit4] > Throwable #1:
com.carrotsearch.randomizedtesting.ThreadLeakError: 1 thread leaked from SUITE
scope at org.apache.solr.cloud.rule.RulesTest:
[junit4] > 1) Thread[id=16595, name=qtp27345429-16595,
state=TIMED_WAITING, group=TGRP-RulesTest]
[junit4] > at sun.misc.Unsafe.park(Native Method)
[junit4] > at
java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215)
[junit4] > at
java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2163)
[junit4] > at
org.eclipse.jetty.util.thread.ReservedThreadExecutor$ReservedThread.reservedWait(ReservedThreadExecutor.java:308)
[junit4] > at
org.eclipse.jetty.util.thread.ReservedThreadExecutor$ReservedThread.run(ReservedThreadExecutor.java:373)
[junit4] > at
org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:708)
[junit4] > at
org.eclipse.jetty.util.thread.QueuedThreadPool$2.run(QueuedThreadPool.java:626)
[junit4] > at java.lang.Thread.run(Thread.java:748)
[junit4] > at
__randomizedtesting.SeedInfo.seed([EBBA7F4A24CDA47F]:0)Throwable #2:
com.carrotsearch.randomizedtesting.ThreadLeakError: There are still zombie
threads that couldn't be terminated:
[junit4] > 1) Thread[id=16595, name=qtp27345429-16595,
state=TIMED_WAITING, group=TGRP-RulesTest]
[junit4] > at sun.misc.Unsafe.park(Native Method)
[junit4] > at
java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215)
[junit4] > at
java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2163)
[junit4] > at
org.eclipse.jetty.util.thread.ReservedThreadExecutor$ReservedThread.reservedWait(ReservedThreadExecutor.java:308)
[junit4] > at
org.eclipse.jetty.util.thread.ReservedThreadExecutor$ReservedThread.run(ReservedThreadExecutor.java:373)
[junit4] > at
org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:708)
[junit4] > at
org.eclipse.jetty.util.thread.QueuedThreadPool$2.run(QueuedThreadPool.java:626)
[junit4] > at java.lang.Thread.run(Thread.java:748)
[junit4] > at
__randomizedtesting.SeedInfo.seed([EBBA7F4A24CDA47F]:0)
[junit4] Completed [392/774 (3!)] on J1 in 84.84s, 7 tests, 2 errors <<<
FAILURES!
[...truncated 45166 lines...]
---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscr...@lucene.apache.org
For additional commands, e-mail: dev-h...@lucene.apache.org
