Build: https://jenkins.thetaphi.de/job/Lucene-Solr-master-Solaris/1688/
Java: 64bit/jdk1.8.0 -XX:-UseCompressedOops -XX:+UseG1GC
3 tests failed.
FAILED:
junit.framework.TestSuite.org.apache.solr.handler.clustering.DistributedClusteringComponentTest
Error Message:
1 thread leaked from SUITE scope at
org.apache.solr.handler.clustering.DistributedClusteringComponentTest: 1)
Thread[id=37, name=qtp1278777971-37, state=TIMED_WAITING,
group=TGRP-DistributedClusteringComponentTest] 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.handler.clustering.DistributedClusteringComponentTest:
1) Thread[id=37, name=qtp1278777971-37, state=TIMED_WAITING,
group=TGRP-DistributedClusteringComponentTest]
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([8AEF5CD4F3FBC58]:0)
FAILED:
junit.framework.TestSuite.org.apache.solr.handler.clustering.DistributedClusteringComponentTest
Error Message:
There are still zombie threads that couldn't be terminated: 1) Thread[id=37,
name=qtp1278777971-37, state=TIMED_WAITING,
group=TGRP-DistributedClusteringComponentTest] 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=37, name=qtp1278777971-37, state=TIMED_WAITING,
group=TGRP-DistributedClusteringComponentTest]
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([8AEF5CD4F3FBC58]:0)
FAILED:
org.apache.solr.cloud.autoscaling.ComputePlanActionTest.testNodeWithMultipleReplicasLost
Error Message:
The operations computed by ComputePlanAction should not be null
SolrClientNodeStateProvider.DEBUG{AFTER_ACTION=[compute_plan, null],
BEFORE_ACTION=[compute_plan, null]}
Stack Trace:
java.lang.AssertionError: The operations computed by ComputePlanAction should
not be null SolrClientNodeStateProvider.DEBUG{AFTER_ACTION=[compute_plan,
null], BEFORE_ACTION=[compute_plan, null]}
at
__randomizedtesting.SeedInfo.seed([4324EF2CAA18D31F:73E40EAE226A3243]:0)
at org.junit.Assert.fail(Assert.java:93)
at org.junit.Assert.assertTrue(Assert.java:43)
at org.junit.Assert.assertNotNull(Assert.java:526)
at
org.apache.solr.cloud.autoscaling.ComputePlanActionTest.testNodeWithMultipleReplicasLost(ComputePlanActionTest.java:291)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at
sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:498)
at
com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1737)
at
com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:934)
at
com.carrotsearch.randomizedtesting.RandomizedRunner$9.evaluate(RandomizedRunner.java:970)
at
com.carrotsearch.randomizedtesting.RandomizedRunner$10.evaluate(RandomizedRunner.java:984)
at
com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
at
org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:49)
at
org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
at
org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:48)
at
org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
at
org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
at
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at
com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368)
at
com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:817)
at
com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:468)
at
com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:943)
at
com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:829)
at
com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:879)
at
com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:890)
at
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at
com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
at
org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
at
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at
org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:41)
at
com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
at
com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
at
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at
org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:53)
at
org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
at
org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
at
org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:54)
at
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at
com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368)
at java.lang.Thread.run(Thread.java:748)
Build Log:
[...truncated 13936 lines...]
[junit4] Suite: org.apache.solr.cloud.autoscaling.ComputePlanActionTest
[junit4] 2> Creating dataDir:
/export/home/jenkins/workspace/Lucene-Solr-master-Solaris/solr/build/solr-core/test/J0/temp/solr.cloud.autoscaling.ComputePlanActionTest_4324EF2CAA18D31F-001/init-core-data-001
[junit4] 2> 3858239 WARN
(SUITE-ComputePlanActionTest-seed#[4324EF2CAA18D31F]-worker) [ ]
o.a.s.SolrTestCaseJ4 startTrackingSearchers: numOpens=24 numCloses=24
[junit4] 2> 3858239 INFO
(SUITE-ComputePlanActionTest-seed#[4324EF2CAA18D31F]-worker) [ ]
o.a.s.SolrTestCaseJ4 Using PointFields (NUMERIC_POINTS_SYSPROP=true)
w/NUMERIC_DOCVALUES_SYSPROP=true
[junit4] 2> 3858241 INFO
(SUITE-ComputePlanActionTest-seed#[4324EF2CAA18D31F]-worker) [ ]
o.a.s.SolrTestCaseJ4 Randomized ssl (false) and clientAuth (false) via:
@org.apache.solr.util.RandomizeSSL(reason=, value=NaN, ssl=NaN, clientAuth=NaN)
[junit4] 2> 3858241 INFO
(SUITE-ComputePlanActionTest-seed#[4324EF2CAA18D31F]-worker) [ ]
o.a.s.SolrTestCaseJ4 SecureRandom sanity checks:
test.solr.allowed.securerandom=null & java.security.egd=file:/dev/./urandom
[junit4] 2> 3858242 INFO
(SUITE-ComputePlanActionTest-seed#[4324EF2CAA18D31F]-worker) [ ]
o.a.s.c.MiniSolrCloudCluster Starting cluster of 1 servers in
/export/home/jenkins/workspace/Lucene-Solr-master-Solaris/solr/build/solr-core/test/J0/temp/solr.cloud.autoscaling.ComputePlanActionTest_4324EF2CAA18D31F-001/tempDir-001
[junit4] 2> 3858242 INFO
(SUITE-ComputePlanActionTest-seed#[4324EF2CAA18D31F]-worker) [ ]
o.a.s.c.ZkTestServer STARTING ZK TEST SERVER
[junit4] 2> 3858243 INFO (Thread-9248) [ ] o.a.s.c.ZkTestServer client
port:0.0.0.0/0.0.0.0:0
[junit4] 2> 3858243 INFO (Thread-9248) [ ] o.a.s.c.ZkTestServer
Starting server
[junit4] 2> 3858244 ERROR (Thread-9248) [ ] 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> 3858342 INFO
(SUITE-ComputePlanActionTest-seed#[4324EF2CAA18D31F]-worker) [ ]
o.a.s.c.ZkTestServer start zk server on port:61117
[junit4] 2> 3858344 INFO (zkConnectionManagerCallback-6373-thread-1) [
] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 3858348 INFO (jetty-launcher-6370-thread-1) [ ]
o.e.j.s.Server jetty-9.4.8.v20171121, build timestamp:
2017-11-22T10:27:37+13:00, git hash: 82b8fb23f757335bb3329d540ce37a2a2615f0a8
[junit4] 2> 3858349 INFO (jetty-launcher-6370-thread-1) [ ]
o.e.j.s.session DefaultSessionIdManager workerName=node0
[junit4] 2> 3858349 INFO (jetty-launcher-6370-thread-1) [ ]
o.e.j.s.session No SessionScavenger set, using defaults
[junit4] 2> 3858349 INFO (jetty-launcher-6370-thread-1) [ ]
o.e.j.s.session Scavenging every 600000ms
[junit4] 2> 3858349 INFO (jetty-launcher-6370-thread-1) [ ]
o.e.j.s.h.ContextHandler Started
o.e.j.s.ServletContextHandler@293e4c9{/solr,null,AVAILABLE}
[junit4] 2> 3858350 INFO (jetty-launcher-6370-thread-1) [ ]
o.e.j.s.AbstractConnector Started
ServerConnector@15eebe3c{HTTP/1.1,[http/1.1]}{127.0.0.1:38925}
[junit4] 2> 3858350 INFO (jetty-launcher-6370-thread-1) [ ]
o.e.j.s.Server Started @3865637ms
[junit4] 2> 3858350 INFO (jetty-launcher-6370-thread-1) [ ]
o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr,
hostPort=38925}
[junit4] 2> 3858350 ERROR (jetty-launcher-6370-thread-1) [ ]
o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be
missing or incomplete.
[junit4] 2> 3858350 INFO (jetty-launcher-6370-thread-1) [ ]
o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr™ version
8.0.0
[junit4] 2> 3858350 INFO (jetty-launcher-6370-thread-1) [ ]
o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 3858350 INFO (jetty-launcher-6370-thread-1) [ ]
o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 3858350 INFO (jetty-launcher-6370-thread-1) [ ]
o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time:
2018-02-20T02:25:16.592Z
[junit4] 2> 3858352 INFO (zkConnectionManagerCallback-6375-thread-1) [
] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 3858353 INFO (jetty-launcher-6370-thread-1) [ ]
o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 3858359 INFO (jetty-launcher-6370-thread-1) [ ]
o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:61117/solr
[junit4] 2> 3858360 INFO (zkConnectionManagerCallback-6379-thread-1) [
] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 3858363 INFO
(zkConnectionManagerCallback-6381-thread-1-processing-n:127.0.0.1:38925_solr)
[n:127.0.0.1:38925_solr ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 3858502 INFO (jetty-launcher-6370-thread-1)
[n:127.0.0.1:38925_solr ] o.a.s.c.Overseer Overseer (id=null) closing
[junit4] 2> 3858503 INFO (jetty-launcher-6370-thread-1)
[n:127.0.0.1:38925_solr ] o.a.s.c.OverseerElectionContext I am going to be
the leader 127.0.0.1:38925_solr
[junit4] 2> 3858504 INFO (jetty-launcher-6370-thread-1)
[n:127.0.0.1:38925_solr ] o.a.s.c.Overseer Overseer
(id=72228692014661635-127.0.0.1:38925_solr-n_0000000000) starting
[junit4] 2> 3858513 DEBUG
(OverseerStateUpdate-72228692014661635-127.0.0.1:38925_solr-n_0000000000)
[n:127.0.0.1:38925_solr ] o.a.s.c.Overseer Starting to work on the main queue
[junit4] 2> 3858513 INFO (jetty-launcher-6370-thread-1)
[n:127.0.0.1:38925_solr ] o.a.s.c.ZkController Register node as live in
ZooKeeper:/live_nodes/127.0.0.1:38925_solr
[junit4] 2> 3858514 DEBUG
(OverseerAutoScalingTriggerThread-72228692014661635-127.0.0.1:38925_solr-n_0000000000)
[n:127.0.0.1:38925_solr ] o.a.s.c.a.OverseerTriggerThread Adding
.autoAddReplicas trigger
[junit4] 2> 3858515 DEBUG
(OverseerAutoScalingTriggerThread-72228692014661635-127.0.0.1:38925_solr-n_0000000000)
[n:127.0.0.1:38925_solr ] o.a.s.c.a.OverseerTriggerThread Refreshing
/autoscaling.json with znode version 1
[junit4] 2> 3858516 DEBUG
(OverseerAutoScalingTriggerThread-72228692014661635-127.0.0.1:38925_solr-n_0000000000)
[n:127.0.0.1:38925_solr ] o.a.s.c.a.NodeLostTrigger Initial livenodes: []
[junit4] 2> 3858516 DEBUG
(OverseerAutoScalingTriggerThread-72228692014661635-127.0.0.1:38925_solr-n_0000000000)
[n:127.0.0.1:38925_solr ] o.a.s.c.a.OverseerTriggerThread Current
znodeVersion 1, lastZnodeVersion -1
[junit4] 2> 3858516 DEBUG
(OverseerAutoScalingTriggerThread-72228692014661635-127.0.0.1:38925_solr-n_0000000000)
[n:127.0.0.1:38925_solr ] o.a.s.c.a.OverseerTriggerThread Processed trigger
updates upto znodeVersion 1
[junit4] 2> 3858516 INFO
(OverseerStateUpdate-72228692014661635-127.0.0.1:38925_solr-n_0000000000)
[n:127.0.0.1:38925_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (0) -> (1)
[junit4] 2> 3858519 DEBUG
(OverseerAutoScalingTriggerThread-72228692014661635-127.0.0.1:38925_solr-n_0000000000)
[n:127.0.0.1:38925_solr ] o.a.s.c.a.OverseerTriggerThread -- clean old
nodeAdded markers
[junit4] 2> 3858520 DEBUG
(OverseerAutoScalingTriggerThread-72228692014661635-127.0.0.1:38925_solr-n_0000000000)
[n:127.0.0.1:38925_solr ] o.a.s.c.a.OverseerTriggerThread Current
znodeVersion 1, lastZnodeVersion 1
[junit4] 2> 3858521 DEBUG (ScheduledTrigger-12741-thread-1)
[n:127.0.0.1:38925_solr ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger:
.auto_add_replicas with currently live nodes: 1
[junit4] 2> 3858603 INFO (jetty-launcher-6370-thread-1)
[n:127.0.0.1:38925_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for
'solr_38925.solr.node' (registry 'solr.node') enabled at server:
com.sun.jmx.mbeanserver.JmxMBeanServer@68ced282
[junit4] 2> 3858609 INFO (jetty-launcher-6370-thread-1)
[n:127.0.0.1:38925_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for
'solr_38925.solr.jvm' (registry 'solr.jvm') enabled at server:
com.sun.jmx.mbeanserver.JmxMBeanServer@68ced282
[junit4] 2> 3858609 INFO (jetty-launcher-6370-thread-1)
[n:127.0.0.1:38925_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for
'solr_38925.solr.jetty' (registry 'solr.jetty') enabled at server:
com.sun.jmx.mbeanserver.JmxMBeanServer@68ced282
[junit4] 2> 3858609 INFO (jetty-launcher-6370-thread-1)
[n:127.0.0.1:38925_solr ] o.a.s.c.CorePropertiesLocator Found 0 core
definitions underneath
/export/home/jenkins/workspace/Lucene-Solr-master-Solaris/solr/build/solr-core/test/J0/temp/solr.cloud.autoscaling.ComputePlanActionTest_4324EF2CAA18D31F-001/tempDir-001/node1/.
[junit4] 2> 3858622 INFO (zkConnectionManagerCallback-6385-thread-1) [
] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 3858626 INFO (zkConnectionManagerCallback-6389-thread-1) [
] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 3858629 INFO
(SUITE-ComputePlanActionTest-seed#[4324EF2CAA18D31F]-worker) [ ]
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 3858630 INFO
(SUITE-ComputePlanActionTest-seed#[4324EF2CAA18D31F]-worker) [ ]
o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:61117/solr ready
[junit4] 2> 3858644 INFO
(TEST-ComputePlanActionTest.testNodeAdded-seed#[4324EF2CAA18D31F]) [ ]
o.a.s.SolrTestCaseJ4 ###Starting testNodeAdded
[junit4] 2> 3858645 DEBUG
(zkCallback-6380-thread-1-processing-n:127.0.0.1:38925_solr)
[n:127.0.0.1:38925_solr ] o.a.s.c.a.OverseerTriggerThread Refreshing
/autoscaling.json with znode version 2
[junit4] 2> 3858645 DEBUG
(OverseerAutoScalingTriggerThread-72228692014661635-127.0.0.1:38925_solr-n_0000000000)
[n:127.0.0.1:38925_solr ] o.a.s.c.a.OverseerTriggerThread Processed trigger
updates upto znodeVersion 2
[junit4] 2> 3858646 INFO
(TEST-ComputePlanActionTest.testNodeAdded-seed#[4324EF2CAA18D31F]) [ ]
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 3858647 DEBUG
(OverseerAutoScalingTriggerThread-72228692014661635-127.0.0.1:38925_solr-n_0000000000)
[n:127.0.0.1:38925_solr ] o.a.s.c.a.OverseerTriggerThread -- clean old
nodeLost markers
[junit4] 2> 3858648 DEBUG
(OverseerAutoScalingTriggerThread-72228692014661635-127.0.0.1:38925_solr-n_0000000000)
[n:127.0.0.1:38925_solr ] o.a.s.c.a.OverseerTriggerThread -- clean old
nodeAdded markers
[junit4] 2> 3858648 DEBUG
(OverseerAutoScalingTriggerThread-72228692014661635-127.0.0.1:38925_solr-n_0000000000)
[n:127.0.0.1:38925_solr ] o.a.s.c.a.OverseerTriggerThread Current
znodeVersion 2, lastZnodeVersion 2
[junit4] 2> 3858651 INFO (qtp2092840606-33572) [n:127.0.0.1:38925_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> 3858652 DEBUG (qtp2092840606-33569) [n:127.0.0.1:38925_solr
] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
[junit4] 2> 3858653 INFO (qtp2092840606-33569) [n:127.0.0.1:38925_solr
] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/autoscaling
params={wt=javabin&version=2} status=0 QTime=3
[junit4] 2> 3858653 DEBUG
(zkCallback-6380-thread-1-processing-n:127.0.0.1:38925_solr)
[n:127.0.0.1:38925_solr ] o.a.s.c.a.OverseerTriggerThread Refreshing
/autoscaling.json with znode version 3
[junit4] 2> 3858653 DEBUG
(OverseerAutoScalingTriggerThread-72228692014661635-127.0.0.1:38925_solr-n_0000000000)
[n:127.0.0.1:38925_solr ] o.a.s.c.a.OverseerTriggerThread Processed trigger
updates upto znodeVersion 3
[junit4] 2> 3858653 DEBUG
(OverseerAutoScalingTriggerThread-72228692014661635-127.0.0.1:38925_solr-n_0000000000)
[n:127.0.0.1:38925_solr ] o.a.s.c.a.OverseerTriggerThread -- clean old
nodeLost markers
[junit4] 2> 3858654 DEBUG
(OverseerAutoScalingTriggerThread-72228692014661635-127.0.0.1:38925_solr-n_0000000000)
[n:127.0.0.1:38925_solr ] o.a.s.c.a.OverseerTriggerThread -- clean old
nodeAdded markers
[junit4] 2> 3858654 DEBUG
(OverseerAutoScalingTriggerThread-72228692014661635-127.0.0.1:38925_solr-n_0000000000)
[n:127.0.0.1:38925_solr ] o.a.s.c.a.OverseerTriggerThread Current
znodeVersion 3, lastZnodeVersion 3
[junit4] 2> 3858655 INFO (qtp2092840606-33572) [n:127.0.0.1:38925_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> 3858655 DEBUG (qtp2092840606-33571) [n:127.0.0.1:38925_solr
] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
[junit4] 2> 3858656 INFO (qtp2092840606-33571) [n:127.0.0.1:38925_solr
] o.a.s.s.HttpSolrCall [admin] webapp=null path=/cluster/autoscaling
params={wt=javabin&version=2} status=0 QTime=3
[junit4] 2> 3858656 DEBUG
(zkCallback-6380-thread-1-processing-n:127.0.0.1:38925_solr)
[n:127.0.0.1:38925_solr ] o.a.s.c.a.OverseerTriggerThread Refreshing
/autoscaling.json with znode version 4
[junit4] 2> 3858657 DEBUG
(OverseerAutoScalingTriggerThread-72228692014661635-127.0.0.1:38925_solr-n_0000000000)
[n:127.0.0.1:38925_solr ] o.a.s.c.a.OverseerTriggerThread Processed trigger
updates upto znodeVersion 4
[junit4] 2> 3858657 DEBUG
(OverseerAutoScalingTriggerThread-72228692014661635-127.0.0.1:38925_solr-n_0000000000)
[n:127.0.0.1:38925_solr ] o.a.s.c.a.OverseerTriggerThread -- clean old
nodeLost markers
[junit4] 2> 3858657 DEBUG
(OverseerAutoScalingTriggerThread-72228692014661635-127.0.0.1:38925_solr-n_0000000000)
[n:127.0.0.1:38925_solr ] o.a.s.c.a.OverseerTriggerThread -- clean old
nodeAdded markers
[junit4] 2> 3858658 DEBUG
(OverseerAutoScalingTriggerThread-72228692014661635-127.0.0.1:38925_solr-n_0000000000)
[n:127.0.0.1:38925_solr ] o.a.s.c.a.OverseerTriggerThread Current
znodeVersion 4, lastZnodeVersion 4
[junit4] 2> 3858660 INFO (qtp2092840606-33571) [n:127.0.0.1:38925_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> 3858660 DEBUG (qtp2092840606-33574) [n:127.0.0.1:38925_solr
] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
[junit4] 2> 3858661 INFO (qtp2092840606-33574) [n:127.0.0.1:38925_solr
] o.a.s.s.HttpSolrCall [admin] webapp=null path=/cluster/autoscaling
params={wt=javabin&version=2} status=0 QTime=2
[junit4] 2> 3858661 DEBUG
(zkCallback-6380-thread-1-processing-n:127.0.0.1:38925_solr)
[n:127.0.0.1:38925_solr ] o.a.s.c.a.OverseerTriggerThread Refreshing
/autoscaling.json with znode version 5
[junit4] 2> 3858662 DEBUG
(zkCallback-6380-thread-1-processing-n:127.0.0.1:38925_solr)
[n:127.0.0.1:38925_solr ] o.a.s.c.a.NodeAddedTrigger Initial livenodes:
[127.0.0.1:38925_solr]
[junit4] 2> 3858662 DEBUG
(zkCallback-6380-thread-1-processing-n:127.0.0.1:38925_solr)
[n:127.0.0.1:38925_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> 3858662 DEBUG
(OverseerAutoScalingTriggerThread-72228692014661635-127.0.0.1:38925_solr-n_0000000000)
[n:127.0.0.1:38925_solr ] o.a.s.c.a.OverseerTriggerThread Processed trigger
updates upto znodeVersion 5
[junit4] 2> 3858663 INFO (qtp2092840606-33574) [n:127.0.0.1:38925_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> 3858663 DEBUG (qtp2092840606-33572) [n:127.0.0.1:38925_solr
] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
[junit4] 2> 3858664 INFO (qtp2092840606-33572) [n:127.0.0.1:38925_solr
] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/autoscaling
params={wt=javabin&version=2} status=0 QTime=3
[junit4] 2> 3858664 DEBUG
(zkCallback-6380-thread-1-processing-n:127.0.0.1:38925_solr)
[n:127.0.0.1:38925_solr ] o.a.s.c.a.OverseerTriggerThread Refreshing
/autoscaling.json with znode version 6
[junit4] 2> 3858665 INFO (qtp2092840606-33571) [n:127.0.0.1:38925_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> 3858665 DEBUG
(zkCallback-6380-thread-1-processing-n:127.0.0.1:38925_solr)
[n:127.0.0.1:38925_solr ] o.a.s.c.a.NodeAddedTrigger Initial livenodes:
[127.0.0.1:38925_solr]
[junit4] 2> 3858665 DEBUG
(zkCallback-6380-thread-1-processing-n:127.0.0.1:38925_solr)
[n:127.0.0.1:38925_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> 3858666 DEBUG
(OverseerAutoScalingTriggerThread-72228692014661635-127.0.0.1:38925_solr-n_0000000000)
[n:127.0.0.1:38925_solr ] o.a.s.c.a.OverseerTriggerThread -- clean old
nodeLost markers
[junit4] 2> 3858667 INFO
(OverseerThreadFactory-12743-thread-1-processing-n:127.0.0.1:38925_solr)
[n:127.0.0.1:38925_solr ] o.a.s.c.a.c.CreateCollectionCmd Create collection
testNodeAdded
[junit4] 2> 3858667 DEBUG (ScheduledTrigger-12741-thread-1)
[n:127.0.0.1:38925_solr ] o.a.s.c.a.NodeAddedTrigger Running
NodeAddedTrigger node_added_trigger
[junit4] 2> 3858667 DEBUG
(OverseerAutoScalingTriggerThread-72228692014661635-127.0.0.1:38925_solr-n_0000000000)
[n:127.0.0.1:38925_solr ] o.a.s.c.a.OverseerTriggerThread Current
znodeVersion 6, lastZnodeVersion 5
[junit4] 2> 3858667 DEBUG (ScheduledTrigger-12741-thread-1)
[n:127.0.0.1:38925_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 1
[junit4] 2> 3858668 DEBUG
(OverseerAutoScalingTriggerThread-72228692014661635-127.0.0.1:38925_solr-n_0000000000)
[n:127.0.0.1:38925_solr ] o.a.s.c.a.OverseerTriggerThread Processed trigger
updates upto znodeVersion 6
[junit4] 2> 3858668 DEBUG
(OverseerAutoScalingTriggerThread-72228692014661635-127.0.0.1:38925_solr-n_0000000000)
[n:127.0.0.1:38925_solr ] o.a.s.c.a.OverseerTriggerThread -- clean old
nodeLost markers
[junit4] 2> 3858668 WARN
(OverseerThreadFactory-12743-thread-1-processing-n:127.0.0.1:38925_solr)
[n:127.0.0.1:38925_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> 3858668 DEBUG
(OverseerAutoScalingTriggerThread-72228692014661635-127.0.0.1:38925_solr-n_0000000000)
[n:127.0.0.1:38925_solr ] o.a.s.c.a.OverseerTriggerThread Current
znodeVersion 6, lastZnodeVersion 6
[junit4] 2> 3858670 INFO (qtp2092840606-33572) [n:127.0.0.1:38925_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> 3858670 INFO
(OverseerThreadFactory-12743-thread-1-processing-n:127.0.0.1:38925_solr)
[n:127.0.0.1:38925_solr ] o.a.s.c.s.c.a.PolicyHelper returnSession,
curr-time 2610748363 sessionWrapper.createTime 2610748362892400,
this.sessionWrapper.createTime 2610748362892400
[junit4] 2> 3858676 DEBUG
(OverseerStateUpdate-72228692014661635-127.0.0.1:38925_solr-n_0000000000)
[n:127.0.0.1:38925_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> 3858677 DEBUG
(OverseerStateUpdate-72228692014661635-127.0.0.1:38925_solr-n_0000000000)
[n:127.0.0.1:38925_solr ] o.a.s.c.o.ClusterStateMutator building a new
cName: testNodeAdded
[junit4] 2> 3858677 DEBUG
(OverseerStateUpdate-72228692014661635-127.0.0.1:38925_solr-n_0000000000)
[n:127.0.0.1:38925_solr ] o.a.s.c.o.ZkStateWriter going to create_collection
/collections/testNodeAdded/state.json
[junit4] 2> 3858782 DEBUG
(OverseerStateUpdate-72228692014661635-127.0.0.1:38925_solr-n_0000000000)
[n:127.0.0.1:38925_solr ] o.a.s.c.Overseer processMessage: queueSize: 1,
message = {
[junit4] 2> "operation":"ADDREPLICA",
[junit4] 2> "collection":"testNodeAdded",
[junit4] 2> "shard":"shard1",
[junit4] 2> "core":"testNodeAdded_shard1_replica_n1",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"http://127.0.0.1:38925/solr";,
[junit4] 2> "type":"NRT",
[junit4] 2> "waitForFinalState":"false"} current state version: 0
[junit4] 2> 3858782 INFO
(OverseerStateUpdate-72228692014661635-127.0.0.1:38925_solr-n_0000000000)
[n:127.0.0.1:38925_solr ] o.a.s.c.o.SliceMutator createReplica() {
[junit4] 2> "operation":"ADDREPLICA",
[junit4] 2> "collection":"testNodeAdded",
[junit4] 2> "shard":"shard1",
[junit4] 2> "core":"testNodeAdded_shard1_replica_n1",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"http://127.0.0.1:38925/solr";,
[junit4] 2> "type":"NRT",
[junit4] 2> "waitForFinalState":"false"}
[junit4] 2> 3858785 DEBUG
(OverseerStateUpdate-72228692014661635-127.0.0.1:38925_solr-n_0000000000)
[n:127.0.0.1:38925_solr ] o.a.s.c.o.SliceMutator Old Slice: shard1:{
[junit4] 2> "range":"80000000-7fffffff",
[junit4] 2> "state":"active",
[junit4] 2> "replicas":{}}
[junit4] 2> 3858785 DEBUG
(OverseerStateUpdate-72228692014661635-127.0.0.1:38925_solr-n_0000000000)
[n:127.0.0.1:38925_solr ] o.a.s.c.o.SliceMutator New Slice: shard1:{
[junit4] 2> "range":"80000000-7fffffff",
[junit4] 2> "state":"active",
[junit4] 2> "replicas":{"core_node3":{
[junit4] 2> "core":"testNodeAdded_shard1_replica_n1",
[junit4] 2> "base_url":"http://127.0.0.1:38925/solr";,
[junit4] 2> "state":"down",
[junit4] 2> "node_name":null,
[junit4] 2> "type":"NRT"}}}
[junit4] 2> 3858786 DEBUG
(OverseerStateUpdate-72228692014661635-127.0.0.1:38925_solr-n_0000000000)
[n:127.0.0.1:38925_solr ] o.a.s.c.Overseer processMessage: queueSize: 2,
message = {
[junit4] 2> "operation":"ADDREPLICA",
[junit4] 2> "collection":"testNodeAdded",
[junit4] 2> "shard":"shard1",
[junit4] 2> "core":"testNodeAdded_shard1_replica_n2",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"http://127.0.0.1:38925/solr";,
[junit4] 2> "type":"NRT",
[junit4] 2> "waitForFinalState":"false"} current state version: 0
[junit4] 2> 3858786 INFO
(OverseerStateUpdate-72228692014661635-127.0.0.1:38925_solr-n_0000000000)
[n:127.0.0.1:38925_solr ] o.a.s.c.o.SliceMutator createReplica() {
[junit4] 2> "operation":"ADDREPLICA",
[junit4] 2> "collection":"testNodeAdded",
[junit4] 2> "shard":"shard1",
[junit4] 2> "core":"testNodeAdded_shard1_replica_n2",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"http://127.0.0.1:38925/solr";,
[junit4] 2> "type":"NRT",
[junit4] 2> "waitForFinalState":"false"}
[junit4] 2> 3858788 DEBUG
(OverseerStateUpdate-72228692014661635-127.0.0.1:38925_solr-n_0000000000)
[n:127.0.0.1:38925_solr ] o.a.s.c.o.SliceMutator Old Slice: shard1:{
[junit4] 2> "range":"80000000-7fffffff",
[junit4] 2> "state":"active",
[junit4] 2> "replicas":{"core_node3":{
[junit4] 2> "core":"testNodeAdded_shard1_replica_n1",
[junit4] 2> "base_url":"http://127.0.0.1:38925/solr";,
[junit4] 2> "state":"down",
[junit4] 2> "node_name":null,
[junit4] 2> "type":"NRT"}}}
[junit4] 2> 3858788 DEBUG
(OverseerStateUpdate-72228692014661635-127.0.0.1:38925_solr-n_0000000000)
[n:127.0.0.1:38925_solr ] o.a.s.c.o.SliceMutator New Slice: shard1:{
[junit4] 2> "range":"80000000-7fffffff",
[junit4] 2> "state":"active",
[junit4] 2> "replicas":{
[junit4] 2> "core_node3":{
[junit4] 2> "core":"testNodeAdded_shard1_replica_n1",
[junit4] 2> "base_url":"http://127.0.0.1:38925/solr";,
[junit4] 2> "state":"down",
[junit4] 2> "node_name":null,
[junit4] 2> "type":"NRT"},
[junit4] 2> "core_node4":{
[junit4] 2> "core":"testNodeAdded_shard1_replica_n2",
[junit4] 2> "base_url":"http://127.0.0.1:38925/solr";,
[junit4] 2> "state":"down",
[junit4] 2> "node_name":null,
[junit4] 2> "type":"NRT"}}}
[junit4] 2> 3858889 DEBUG
(OverseerStateUpdate-72228692014661635-127.0.0.1:38925_solr-n_0000000000)
[n:127.0.0.1:38925_solr ] o.a.s.c.o.ZkStateWriter going to update_collection
/collections/testNodeAdded/state.json version: 0
[junit4] 2> 3858989 INFO (qtp2092840606-33572) [n:127.0.0.1:38925_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> 3858989 INFO (qtp2092840606-33572) [n:127.0.0.1:38925_solr
] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for
2147483647 transient cores
[junit4] 2> 3858989 INFO (qtp2092840606-33575) [n:127.0.0.1:38925_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> 3858994 DEBUG
(OverseerStateUpdate-72228692014661635-127.0.0.1:38925_solr-n_0000000000)
[n:127.0.0.1:38925_solr ] o.a.s.c.Overseer processMessage: queueSize: 2,
message = {
[junit4] 2> "core":"testNodeAdded_shard1_replica_n2",
[junit4] 2> "core_node_name":"core_node4",
[junit4] 2> "roles":null,
[junit4] 2> "base_url":"http://127.0.0.1:38925/solr";,
[junit4] 2> "node_name":"127.0.0.1:38925_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> 3858994 DEBUG
(OverseerStateUpdate-72228692014661635-127.0.0.1:38925_solr-n_0000000000)
[n:127.0.0.1:38925_solr ] o.a.s.c.o.ReplicaMutator Update state numShards=1
message={
[junit4] 2> "core":"testNodeAdded_shard1_replica_n2",
[junit4] 2> "core_node_name":"core_node4",
[junit4] 2> "roles":null,
[junit4] 2> "base_url":"http://127.0.0.1:38925/solr";,
[junit4] 2> "node_name":"127.0.0.1:38925_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> 3858994 DEBUG
(OverseerStateUpdate-72228692014661635-127.0.0.1:38925_solr-n_0000000000)
[n:127.0.0.1:38925_solr ] o.a.s.c.o.ReplicaMutator Will update state for
replica:
core_node4:{"core":"testNodeAdded_shard1_replica_n2","base_url":"http://127.0.0.1:38925/solr","node_name":"127.0.0.1:38925_solr","state":"down","type":"NRT"}
[junit4] 2> 3858994 DEBUG
(OverseerStateUpdate-72228692014661635-127.0.0.1:38925_solr-n_0000000000)
[n:127.0.0.1:38925_solr ] o.a.s.c.o.ReplicaMutator Collection is now:
DocCollection(testNodeAdded//collections/testNodeAdded/state.json/1)={
[junit4] 2> "pullReplicas":"0",
[junit4] 2> "replicationFactor":"2",
[junit4] 2> "router":{"name":"compositeId"},
[junit4] 2> "maxShardsPerNode":"1",
[junit4] 2> "autoAddReplicas":"false",
[junit4] 2> "nrtReplicas":"2",
[junit4] 2> "tlogReplicas":"0",
[junit4] 2> "shards":{"shard1":{
[junit4] 2> "range":"80000000-7fffffff",
[junit4] 2> "state":"active",
[junit4] 2> "replicas":{
[junit4] 2> "core_node3":{
[junit4] 2> "core":"testNodeAdded_shard1_replica_n1",
[junit4] 2> "base_url":"http://127.0.0.1:38925/solr";,
[junit4] 2> "state":"down",
[junit4] 2> "node_name":null,
[junit4] 2> "type":"NRT"},
[junit4] 2> "core_node4":{
[junit4] 2> "core":"testNodeAdded_shard1_replica_n2",
[junit4] 2> "base_url":"http://127.0.0.1:38925/solr";,
[junit4] 2> "node_name":"127.0.0.1:38925_solr",
[junit4] 2> "state":"down",
[junit4] 2> "type":"NRT"}}}}}
[junit4] 2> 3858994 DEBUG
(OverseerStateUpdate-72228692014661635-127.0.0.1:38925_solr-n_0000000000)
[n:127.0.0.1:38925_solr ] o.a.s.c.Overseer processMessage: queueSize: 2,
message = {
[junit4] 2> "core":"testNodeAdded_shard1_replica_n1",
[junit4] 2> "core_node_name":"core_node3",
[junit4] 2> "roles":null,
[junit4] 2> "base_url":"http://127.0.0.1:38925/solr";,
[junit4] 2> "node_name":"127.0.0.1:38925_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> 3858994 DEBUG
(OverseerStateUpdate-72228692014661635-127.0.0.1:38925_solr-n_0000000000)
[n:127.0.0.1:38925_solr ] o.a.s.c.o.ReplicaMutator Update state numShards=1
message={
[junit4] 2> "core":"testNodeAdded_shard1_replica_n1",
[junit4] 2> "core_node_name":"core_node3",
[junit4] 2> "roles":null,
[junit4] 2> "base_url":"http://127.0.0.1:38925/solr";,
[junit4] 2> "node_name":"127.0.0.1:38925_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> 3858994 DEBUG
(OverseerStateUpdate-72228692014661635-127.0.0.1:38925_solr-n_0000000000)
[n:127.0.0.1:38925_solr ] o.a.s.c.o.ReplicaMutator Will update state for
replica:
core_node3:{"core":"testNodeAdded_shard1_replica_n1","base_url":"http://127.0.0.1:38925/solr","node_name":"127.0.0.1:38925_solr","state":"down","type":"NRT"}
[junit4] 2> 3858994 DEBUG
(OverseerStateUpdate-72228692014661635-127.0.0.1:38925_solr-n_0000000000)
[n:127.0.0.1:38925_solr ] o.a.s.c.o.ReplicaMutator Collection is now:
DocCollection(testNodeAdded//collections/testNodeAdded/state.json/1)={
[junit4] 2> "pullReplicas":"0",
[junit4] 2> "replicationFactor":"2",
[junit4] 2> "router":{"name":"compositeId"},
[junit4] 2> "maxShardsPerNode":"1",
[junit4] 2> "autoAddReplicas":"false",
[junit4] 2> "nrtReplicas":"2",
[junit4] 2> "tlogReplicas":"0",
[junit4] 2> "shards":{"shard1":{
[junit4] 2> "range":"80000000-7fffffff",
[junit4] 2> "state":"active",
[junit4] 2> "replicas":{
[junit4] 2> "core_node3":{
[junit4] 2> "core":"testNodeAdded_shard1_replica_n1",
[junit4] 2> "base_url":"http://127.0.0.1:38925/solr";,
[junit4] 2> "node_name":"127.0.0.1:38925_solr",
[junit4] 2> "state":"down",
[junit4] 2> "type":"NRT"},
[junit4] 2> "core_node4":{
[junit4] 2> "core":"testNodeAdded_shard1_replica_n2",
[junit4] 2> "base_url":"http://127.0.0.1:38925/solr";,
[junit4] 2> "node_name":"127.0.0.1:38925_solr",
[junit4] 2> "state":"down",
[junit4] 2> "type":"NRT"}}}}}
[junit4] 2> 3859095 DEBUG
(OverseerStateUpdate-72228692014661635-127.0.0.1:38925_solr-n_0000000000)
[n:127.0.0.1:38925_solr ] o.a.s.c.o.ZkStateWriter going to update_collection
/collections/testNodeAdded/state.json version: 1
[junit4] 2> 3859096 INFO
(zkCallback-6380-thread-1-processing-n:127.0.0.1:38925_solr)
[n:127.0.0.1:38925_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> 3859096 INFO
(zkCallback-6380-thread-2-processing-n:127.0.0.1:38925_solr)
[n:127.0.0.1:38925_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> 3859674 DEBUG (ScheduledTrigger-12741-thread-2)
[n:127.0.0.1:38925_solr ] o.a.s.c.a.NodeAddedTrigger Running
NodeAddedTrigger node_added_trigger
[junit4] 2> 3859674 DEBUG (ScheduledTrigger-12741-thread-2)
[n:127.0.0.1:38925_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 1
[junit4] 2> 3860016 INFO (qtp2092840606-33572) [n:127.0.0.1:38925_solr
c:testNodeAdded s:shard1 r:core_node3 x:testNodeAdded_shard1_replica_n1]
o.a.s.c.SolrConfig Using Lucene MatchVersion: 8.0.0
[junit4] 2> 3860016 INFO (qtp2092840606-33575) [n:127.0.0.1:38925_solr
c:testNodeAdded s:shard1 r:core_node4 x:testNodeAdded_shard1_replica_n2]
o.a.s.c.SolrConfig Using Lucene MatchVersion: 8.0.0
[junit4] 2> 3860034 INFO (qtp2092840606-33572) [n:127.0.0.1:38925_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> 3860034 INFO (qtp2092840606-33575) [n:127.0.0.1:38925_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> 3860036 INFO (qtp2092840606-33575) [n:127.0.0.1:38925_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> 3860036 INFO (qtp2092840606-33572) [n:127.0.0.1:38925_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> 3860037 INFO (qtp2092840606-33572) [n:127.0.0.1:38925_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> 3860036 INFO (qtp2092840606-33575) [n:127.0.0.1:38925_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> 3860037 INFO (qtp2092840606-33575) [n:127.0.0.1:38925_solr
c:testNodeAdded s:shard1 r:core_node4 x:testNodeAdded_shard1_replica_n2]
o.a.s.m.r.SolrJmxReporter JMX monitoring for
'solr_38925.solr.core.testNodeAdded.shard1.replica_n2' (registry
'solr.core.testNodeAdded.shard1.replica_n2') enabled at server:
com.sun.jmx.mbeanserver.JmxMBeanServer@68ced282
[junit4] 2> 3860037 INFO (qtp2092840606-33572) [n:127.0.0.1:38925_solr
c:testNodeAdded s:shard1 r:core_node3 x:testNodeAdded_shard1_replica_n1]
o.a.s.m.r.SolrJmxReporter JMX monitoring for
'solr_38925.solr.core.testNodeAdded.shard1.replica_n1' (registry
'solr.core.testNodeAdded.shard1.replica_n1') enabled at server:
com.sun.jmx.mbeanserver.JmxMBeanServer@68ced282
[junit4] 2> 3860037 INFO (qtp2092840606-33575) [n:127.0.0.1:38925_solr
c:testNodeAdded s:shard1 r:core_node4 x:testNodeAdded_shard1_replica_n2]
o.a.s.c.SolrCore solr.RecoveryStrategy.Builder
[junit4] 2> 3860037 INFO (qtp2092840606-33572) [n:127.0.0.1:38925_solr
c:testNodeAdded s:shard1 r:core_node3 x:testNodeAdded_shard1_replica_n1]
o.a.s.c.SolrCore solr.RecoveryStrategy.Builder
[junit4] 2> 3860037 INFO (qtp2092840606-33575) [n:127.0.0.1:38925_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
[/export/home/jenkins/workspace/Lucene-Solr-master-Solaris/solr/build/solr-core/test/J0/temp/solr.cloud.autoscaling.ComputePlanActionTest_4324EF2CAA18D31F-001/tempDir-001/node1/testNodeAdded_shard1_replica_n2],
dataDir=[/export/home/jenkins/workspace/Lucene-Solr-master-Solaris/solr/build/solr-core/test/J0/temp/solr.cloud.autoscaling.ComputePlanActionTest_4324EF2CAA18D31F-001/tempDir-001/node1/./testNodeAdded_shard1_replica_n2/data/]
[junit4] 2> 3860037 INFO (qtp2092840606-33572) [n:127.0.0.1:38925_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
[/export/home/jenkins/workspace/Lucene-Solr-master-Solaris/solr/build/solr-core/test/J0/temp/solr.cloud.autoscaling.ComputePlanActionTest_4324EF2CAA18D31F-001/tempDir-001/node1/testNodeAdded_shard1_replica_n1],
dataDir=[/export/home/jenkins/workspace/Lucene-Solr-master-Solaris/solr/build/solr-core/test/J0/temp/solr.cloud.autoscaling.ComputePlanActionTest_4324EF2CAA18D31F-001/tempDir-001/node1/./testNodeAdded_shard1_replica_n1/data/]
[junit4] 2> 3860085 INFO (qtp2092840606-33572) [n:127.0.0.1:38925_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> 3860085 INFO (qtp2092840606-33575) [n:127.0.0.1:38925_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> 3860085 INFO (qtp2092840606-33575) [n:127.0.0.1:38925_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> 3860085 INFO (qtp2092840606-33572) [n:127.0.0.1:38925_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> 3860100 INFO (qtp2092840606-33575) [n:127.0.0.1:38925_solr
c:testNodeAdded s:shard1 r:core_node4 x:testNodeAdded_shard1_replica_n2]
o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 3860100 INFO (qtp2092840606-33575) [n:127.0.0.1:38925_solr
c:testNodeAdded s:shard1 r:core_node4 x:testNodeAdded_shard1_replica_n2]
o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 3860100 INFO (qtp2092840606-33572) [n:127.0.0.1:38925_solr
c:testNodeAdded s:shard1 r:core_node3 x:testNodeAdded_shard1_replica_n1]
o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 3860100 INFO (qtp2092840606-33572) [n:127.0.0.1:38925_solr
c:testNodeAdded s:shard1 r:core_node3 x:testNodeAdded_shard1_replica_n1]
o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 3860102 INFO (qtp2092840606-33572) [n:127.0.0.1:38925_solr
c:testNodeAdded s:shard1 r:core_node3 x:testNodeAdded_shard1_replica_n1]
o.a.s.s.SolrIndexSearcher Opening
[Searcher@7f36169f[testNodeAdded_shard1_replica_n1] main]
[junit4] 2> 3860102 INFO (qtp2092840606-33575) [n:127.0.0.1:38925_solr
c:testNodeAdded s:shard1 r:core_node4 x:testNodeAdded_shard1_replica_n2]
o.a.s.s.SolrIndexSearcher Opening
[Searcher@7bc1814[testNodeAdded_shard1_replica_n2] main]
[junit4] 2> 3860103 INFO (qtp2092840606-33572) [n:127.0.0.1:38925_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> 3860104 INFO (qtp2092840606-33575) [n:127.0.0.1:38925_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> 3860104 INFO (qtp2092840606-33572) [n:127.0.0.1:38925_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> 3860104 INFO (qtp2092840606-33575) [n:127.0.0.1:38925_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> 3860105 INFO (qtp2092840606-33572) [n:127.0.0.1:38925_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> 3860105 INFO (qtp2092840606-33575) [n:127.0.0.1:38925_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> 3860105 INFO (qtp2092840606-33572) [n:127.0.0.1:38925_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 1592885005094223872
[junit4] 2> 3860105 INFO (qtp2092840606-33575) [n:127.0.0.1:38925_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 1592885005094223872
[junit4] 2> 3860107 INFO
(searcherExecutor-12746-thread-1-processing-n:127.0.0.1:38925_solr
x:testNodeAdded_shard1_replica_n1 s:shard1 c:testNodeAdded r:core_node3)
[n:127.0.0.1:38925_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@7f36169f[testNodeAdded_shard1_replica_n1]
main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 3860108 INFO
(searcherExecutor-12747-thread-1-processing-n:127.0.0.1:38925_solr
x:testNodeAdded_shard1_replica_n2 s:shard1 c:testNodeAdded r:core_node4)
[n:127.0.0.1:38925_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@7bc1814[testNodeAdded_shard1_replica_n2]
main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 3860111 INFO (qtp2092840606-33575) [n:127.0.0.1:38925_solr
c:testNodeAdded s:shard1 r:core_node4 x:testNodeAdded_shard1_replica_n2]
o.a.s.c.ZkShardTerms Failed to save terms, version is not match, retrying
[junit4] 2> 3860119 INFO (qtp2092840606-33575) [n:127.0.0.1:38925_solr
c:testNodeAdded s:shard1 r:core_node4 x:testNodeAdded_shard1_replica_n2]
o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue.
[junit4] 2> 3860119 INFO (qtp2092840606-33575) [n:127.0.0.1:38925_solr
c:testNodeAdded s:shard1 r:core_node4 x:testNodeAdded_shard1_replica_n2]
o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync
[junit4] 2> 3860119 DEBUG
(OverseerStateUpdate-72228692014661635-127.0.0.1:38925_solr-n_0000000000)
[n:127.0.0.1:38925_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> 3860119 INFO (qtp2092840606-33575) [n:127.0.0.1:38925_solr
c:testNodeAdded s:shard1 r:core_node4 x:testNodeAdded_shard1_replica_n2]
o.a.s.c.SyncStrategy Sync replicas to
http://127.0.0.1:38925/solr/testNodeAdded_shard1_replica_n2/
[junit4] 2> 3860120 INFO (qtp2092840606-33575) [n:127.0.0.1:38925_solr
c:testNodeAdded s:shard1 r:core_node4 x:testNodeAdded_shard1_replica_n2]
o.a.s.u.PeerSync PeerSync: core=testNodeAdded_shard1_replica_n2
url=http://127.0.0.1:38925/solr START
replicas=[http://127.0.0.1:38925/solr/testNodeAdded_shard1_replica_n1/]
nUpdates=100
[junit4] 2> 3860122 INFO (qtp2092840606-33576) [n:127.0.0.1:38925_solr
c:testNodeAdded s:shard1 r:core_node3 x:testNodeAdded_shard1_replica_n1]
o.a.s.c.S.Request [testNodeAdded_shard1_replica_n1] webapp=/solr path=/get
params={distrib=false&qt=/get&fingerprint=false&getVersions=100&wt=javabin&version=2}
status=0 QTime=0
[junit4] 2> 3860220 DEBUG
(OverseerStateUpdate-72228692014661635-127.0.0.1:38925_solr-n_0000000000)
[n:127.0.0.1:38925_solr ] o.a.s.c.o.ZkStateWriter going to update_collection
/collections/testNodeAdded/state.json version: 2
[junit4] 2> 3860221 INFO
(zkCallback-6380-thread-2-processing-n:127.0.0.1:38925_solr)
[n:127.0.0.1:38925_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> 3860221 INFO
(zkCallback-6380-thread-1-processing-n:127.0.0.1:38925_solr)
[n:127.0.0.1:38925_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> 3860420 INFO (qtp2092840606-33575) [n:127.0.0.1:38925_solr
c:testNodeAdded s:shard1 r:core_node4 x:testNodeAdded_shard1_replica_n2]
o.a.s.u.PeerSync PeerSync: core=testNodeAdded_shard1_replica_n2
url=http://127.0.0.1:38925/solr DONE. We have no versions. sync failed.
[junit4] 2> 3860420 INFO (qtp2092840606-33575) [n:127.0.0.1:38925_solr
c:testNodeAdded s:shard1 r:core_node4 x:testNodeAdded_shard1_replica_n2]
o.a.s.c.SyncStrategy Leader's attempt to sync with shard failed, moving to the
next candidate
[junit4] 2> 3860420 INFO (qtp2092840606-33575) [n:127.0.0.1:38925_solr
c:testNodeAdded s:shard1 r:core_node4 x:testNodeAdded_shard1_replica_n2]
o.a.s.c.ShardLeaderElectionContext We failed sync, but we have no versions - we
can't sync in that case - we were active before, so become leader anyway
[junit4] 2> 3860420 INFO (qtp2092840606-33575) [n:127.0.0.1:38925_solr
c:testNodeAdded s:shard1 r:core_node4 x:testNodeAdded_shard1_replica_n2]
o.a.s.c.ShardLeaderElectionContext Found all replicas participating in
election, clear LIR
[junit4] 2> 3860427 INFO (qtp2092840606-33575) [n:127.0.0.1:38925_solr
c:testNodeAdded s:shard1 r:core_node4 x:testNodeAdded_shard1_replica_n2]
o.a.s.c.ShardLeaderElectionContext I am the new leader:
http://127.0.0.1:38925/solr/testNodeAdded_shard1_replica_n2/ shard1
[junit4] 2> 3860429 DEBUG
(OverseerStateUpdate-72228692014661635-127.0.0.1:38925_solr-n_0000000000)
[n:127.0.0.1:38925_solr ] o.a.s.c.Overseer processMessage: queueSize: 1,
message = {
[junit4] 2> "operation":"leader",
[junit4] 2> "shard":"shard1",
[junit4] 2> "collection":"testNodeAdded",
[junit4] 2> "base_url":"http://127.0.0.1:38925/solr";,
[junit4] 2> "core":"testNodeAdded_shard1_replica_n2",
[junit4] 2> "state":"active"} current state version: 0
[junit4] 2> 3860535 DEBUG
(OverseerStateUpdate-72228692014661635-127.0.0.1:38925_solr-n_0000000000)
[n:127.0.0.1:38925_solr ] o.a.s.c.o.ZkStateWriter going to update_collection
/collections/testNodeAdded/state.json version: 3
[junit4] 2> 3860536 INFO
(zkCallback-6380-thread-2-processing-n:127.0.0.1:38925_solr)
[n:127.0.0.1:38925_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> 3860536 INFO
(zkCallback-6380-thread-1-processing-n:127.0.0.1:38925_solr)
[n:127.0.0.1:38925_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> 3860584 INFO (qtp2092840606-33575) [n:127.0.0.1:38925_solr
c:testNodeAdded s:shard1 r:core_node4 x:testNodeAdded_shard1_replica_n2]
o.a.s.c.ZkController I am the leader, no recovery necessary
[junit4] 2> 3860587 DEBUG
(OverseerStateUpdate-72228692014661635-127.0.0.1:38925_solr-n_0000000000)
[n:127.0.0.1:38925_solr ] o.a.s.c.Overseer processMessage: queueSize: 1,
message = {
[junit4] 2> "core":"testNodeAdded_shard1_replica_n2",
[junit4] 2> "core_node_name":"core_node4",
[junit4] 2> "roles":null,
[junit4] 2> "base_url":"http://127.0.0.1:38925/solr";,
[junit4] 2> "node_name":"127.0.0.1:38925_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> 3860587 INFO (qtp2092840606-33575) [n:127.0.0.1:38925_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=1598
[junit4] 2> 3860587 DEBUG
(OverseerStateUpdate-72228692014661635-127.0.0.1:38925_solr-n_0000000000)
[n:127.0.0.1:38925_solr ] o.a.s.c.o.ReplicaMutator Update state numShards=1
message={
[junit4] 2> "core":"testNodeAdded_shard1_replica_n2",
[junit4] 2> "core_node_name":"core_node4",
[junit4] 2> "roles":null,
[junit4] 2> "base_url":"http://127.0.0.1:38925/solr";,
[junit4] 2> "node_name":"127.0.0.1:38925_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> 3860588 DEBUG
(OverseerStateUpdate-72228692014661635-127.0.0.1:38925_solr-n_0000000000)
[n:127.0.0.1:38925_solr ] o.a.s.c.o.ReplicaMutator Will update state for
replica:
core_node4:{"core":"testNodeAdded_shard1_replica_n2","base_url":"http://127.0.0.1:38925/solr","node_name":"127.0.0.1:38925_solr","state":"active","type":"NRT","leader":"true"}
[junit4] 2> 3860588 DEBUG
(OverseerStateUpdate-72228692014661635-127.0.0.1:38925_solr-n_0000000000)
[n:127.0.0.1:38925_solr ] o.a.s.c.o.ReplicaMutator Collection is now:
DocCollection(testNodeAdded//collections/testNodeAdded/state.json/4)={
[junit4] 2> "pullReplicas":"0",
[junit4] 2> "replicationFactor":"2",
[junit4] 2> "router":{"name":"compositeId"},
[junit4] 2> "maxShardsPerNode":"1",
[junit4] 2> "autoAddReplicas":"false",
[junit4] 2> "nrtReplicas":"2",
[junit4] 2> "tlogReplicas":"0",
[junit4] 2> "shards":{"shard1":{
[junit4] 2> "range":"80000000-7fffffff",
[junit4] 2> "state":"active",
[junit4] 2> "replicas":{
[junit4] 2> "core_node3":{
[junit4] 2> "core":"testNodeAdded_shard1_replica_n1",
[junit4] 2> "base_url":"http://127.0.0.1:38925/solr";,
[junit4] 2> "node_name":"127.0.0.1:38925_solr",
[junit4] 2> "state":"down",
[junit4] 2> "type":"NRT"},
[junit4] 2> "core_node4":{
[junit4] 2> "core":"testNodeAdded_shard1_replica_n2",
[junit4] 2> "base_url":"http://127.0.0.1:38925/solr";,
[junit4] 2> "node_name":"127.0.0.1:38925_solr",
[junit4] 2> "state":"active",
[junit4] 2> "type":"NRT",
[junit4] 2> "leader":"true"}}}}}
[junit4] 2> 3860675 DEBUG (ScheduledTrigger-12741-thread-2)
[n:127.0.0.1:38925_solr ] o.a.s.c.a.NodeAddedTrigger Running
NodeAddedTrigger node_added_trigger
[junit4] 2> 3860675 DEBUG (ScheduledTrigger-12741-thread-2)
[n:127.0.0.1:38925_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 1
[junit4] 2> 3860695 DEBUG
(OverseerStateUpdate-72228692014661635-127.0.0.1:38925_solr-n_0000000000)
[n:127.0.0.1:38925_solr ] o.a.s.c.o.ZkStateWriter going to update_collection
/collections/testNodeAdded/state.json version: 4
[junit4] 2> 3860696 INFO
(zkCallback-6380-thread-1-processing-n:127.0.0.1:38925_solr)
[n:127.0.0.1:38925_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> 3860696 INFO
(zkCallback-6380-thread-2-processing-n:127.0.0.1:38925_solr)
[n:127.0.0.1:38925_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> 3861122 DEBUG
(OverseerStateUpdate-72228692014661635-127.0.0.1:38925_solr-n_0000000000)
[n:127.0.0.1:38925_solr ] o.a.s.c.Overseer processMessage: queueSize: 1,
message = {
[junit4] 2> "core":"testNodeAdded_shard1_replica_n1",
[junit4] 2> "core_node_name":"core_node3",
[junit4] 2> "roles":null,
[junit4] 2> "base_url":"http://127.0.0.1:38925/solr";,
[junit4] 2> "node_name":"127.0.0.1:38925_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> 3861122 INFO (qtp2092840606-33572) [n:127.0.0.1:38925_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=2134
[junit4] 2> 3861122 DEBUG
(OverseerStateUpdate-72228692014661635-127.0.0.1:38925_solr-n_0000000000)
[n:127.0.0.1:38925_solr ] o.a.s.c.o.ReplicaMutator Update state numShards=1
message={
[junit4] 2> "core":"testNodeAdded_shard1_replica_n1",
[junit4] 2> "core_node_name":"core_node3",
[junit4] 2> "roles":null,
[junit4] 2> "base_url":"http://127.0.0.1:38925/solr";,
[junit4] 2> "node_name":"127.0.0.1:38925_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> 3861122 DEBUG
(OverseerStateUpdate-72228692014661635-127.0.0.1:38925_solr-n_0000000000)
[n:127.0.0.1:38925_solr ] o.a.s.c.o.ReplicaMutator Will update state for
replica:
core_node3:{"core":"testNodeAdded_shard1_replica_n1","base_url":"http://127.0.0.1:38925/solr","node_name":"127.0.0.1:38925_solr","state":"active","type":"NRT"}
[junit4] 2> 3861122 DEBUG
(OverseerStateUpdate-72228692014661635-127.0.0.1:38925_solr-n_0000000000)
[n:127.0.0.1:38925_solr ] o.a.s.c.o.ReplicaMutator Collection is now:
DocCollection(testNodeAdded//collections/testNodeAdded/state.json/5)={
[junit4] 2> "pullReplicas":"0",
[junit4] 2> "replicationFactor":"2",
[junit4] 2> "router":{"name":"compositeId"},
[junit4] 2> "maxShardsPerNode":"1",
[junit4] 2> "autoAddReplicas":"false",
[junit4] 2> "nrtReplicas":"2",
[junit4] 2> "tlogReplicas":"0",
[junit4] 2> "shards":{"shard1":{
[junit4] 2> "range":"80000000-7fffffff",
[junit4] 2> "state":"active",
[junit4] 2> "replicas":{
[junit4] 2> "core_node3":{
[junit4] 2> "core":"testNodeAdded_shard1_replica_n1",
[junit4] 2> "base_url":"http://127.0.0.1:38925/solr";,
[junit4] 2> "node_name":"127.0.0.1:38925_solr",
[junit4] 2> "state":"active",
[junit4] 2> "type":"NRT"},
[junit4] 2> "core_node4":{
[junit4] 2> "core":"testNodeAdded_shard1_replica_n2",
[junit4] 2> "base_url":"http://127.0.0.1:38925/solr";,
[junit4] 2> "node_name":"127.0.0.1:38925_solr",
[junit4] 2> "state":"active",
[junit4] 2> "type":"NRT",
[junit4] 2> "leader":"true"}}}}}
[junit4] 2> 3861125 INFO (qtp2092840606-33571) [n:127.0.0.1:38925_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> 3861223 DEBUG
(OverseerStateUpdate-72228692014661635-127.0.0.1:38925_solr-n_0000000000)
[n:127.0.0.1:38925_solr ] o.a.s.c.o.ZkStateWriter going to update_collection
/collections/testNodeAdded/state.json version: 5
[junit4] 2> 3861224 INFO
(zkCallback-6380-thread-2-processing-n:127.0.0.1:38925_solr)
[n:127.0.0.1:38925_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> 3861224 INFO
(zkCallback-6380-thread-1-processing-n:127.0.0.1:38925_solr)
[n:127.0.0.1:38925_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> 3861676 DEBUG (ScheduledTrigger-12741-thread-2)
[n:127.0.0.1:38925_solr ] o.a.s.c.a.NodeAddedTrigger Running
NodeAddedTrigger node_added_trigger
[junit4] 2> 3861676 DEBUG (ScheduledTrigger-12741-thread-2)
[n:127.0.0.1:38925_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 1
[junit4] 2> 3862126 INFO (qtp2092840606-33571) [n:127.0.0.1:38925_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=3462
[junit4] 2> 3862131 INFO (qtp2092840606-33575) [n:127.0.0.1:38925_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> 3862133 INFO (qtp2092840606-33576) [n:127.0.0.1:38925_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> 3862134 DEBUG (qtp2092840606-33574) [n:127.0.0.1:38925_solr
] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
[junit4] 2> 3862134 INFO (qtp2092840606-33574) [n:127.0.0.1:38925_solr
] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/autoscaling
params={wt=javabin&version=2} status=0 QTime=5
[junit4] 2> 3862135 DEBUG
(zkCallback-6380-thread-1-processing-n:127.0.0.1:38925_solr)
[n:127.0.0.1:38925_solr ] o.a.s.c.a.OverseerTriggerThread Refreshing
/autoscaling.json with znode version 7
[junit4] 2> 3862135 INFO
(TEST-ComputePlanActionTest.testNodeAdded-seed#[4324EF2CAA18D31F]) [ ]
o.e.j.s.Server jetty-9.4.8.v20171121, build timestamp:
2017-11-22T10:27:37+13:00, git hash: 82b8fb23f757335bb3329d540ce37a2a2615f0a8
[junit4] 2> 3862136 DEBUG
(zkCallback-6380-thread-1-processing-n:127.0.0.1:38925_solr)
[n:127.0.0.1:38925_solr ] o.a.s.c.a.NodeAddedTrigger Initial livenodes:
[127.0.0.1:38925_solr]
[junit4] 2> 3862136 DEBUG
(zkCallback-6380-thread-1-processing-n:127.0.0.1:38925_solr)
[n:127.0.0.1:38925_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> 3862136 DEBUG
(OverseerAutoScalingTriggerThread-72228692014661635-127.0.0.1:38925_solr-n_0000000000)
[n:127.0.0.1:38925_solr ] o.a.s.c.a.OverseerTriggerThread Processed trigger
updates upto znodeVersion 7
[junit4] 2> 3862136 DEBUG
(OverseerAutoScalingTriggerThread-72228692014661635-127.0.0.1:38925_solr-n_0000000000)
[n:127.0.0.1:38925_solr ] o.a.s.c.a.OverseerTriggerThread -- clean old
nodeLost markers
[junit4] 2> 3862137 INFO
(TEST-ComputePlanActionTest.testNodeAdded-seed#[4324EF2CAA18D31F]) [ ]
o.e.j.s.session DefaultSessionIdManager workerName=node0
[junit4] 2> 3862137 DEBUG
(OverseerAutoScalingTriggerThread-72228692014661635-127.0.0.1:38925_solr-n_0000000000)
[n:127.0.0.1:38925_solr ] o.a.s.c.a.OverseerTriggerThread Current
znodeVersion 7, lastZnodeVersion 7
[junit4] 2> 3862137 INFO
(TEST-ComputePlanActionTest.testNodeAdded-seed#[4324EF2CAA18D31F]) [ ]
o.e.j.s.session No SessionScavenger set, using defaults
[junit4] 2> 3862137 INFO
(TEST-ComputePlanActionTest.testNodeAdded-seed#[4324EF2CAA18D31F]) [ ]
o.e.j.s.session Scavenging every 600000ms
[junit4] 2> 3862137 INFO
(TEST-ComputePlanActionTest.testNodeAdded-seed#[4324EF2CAA18D31F]) [ ]
o.e.j.s.h.ContextHandler Started
o.e.j.s.ServletContextHandler@26ace357{/solr,null,AVAILABLE}
[junit4] 2> 3862138 INFO
(TEST-ComputePlanActionTest.testNodeAdded-seed#[4324EF2CAA18D31F]) [ ]
o.e.j.s.AbstractConnector Started
ServerConnector@3a319d8e{HTTP/1.1,[http/1.1]}{127.0.0.1:55048}
[junit4] 2> 3862138 INFO
(TEST-ComputePlanActionTest.testNodeAdded-seed#[4324EF2CAA18D31F]) [ ]
o.e.j.s.Server Started @3869426ms
[junit4] 2> 3862138 INFO
(TEST-ComputePlanActionTest.testNodeAdded-seed#[4324EF2CAA18D31F]) [ ]
o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr,
hostPort=55048}
[junit4] 2> 3862138 ERROR
(TEST-ComputePlanActionTest.testNodeAdded-seed#[4324EF2CAA18D31F]) [ ]
o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be
missing or incomplete.
[junit4] 2> 3862138 INFO
(TEST-ComputePlanActionTest.testNodeAdded-seed#[4324EF2CAA18D31F]) [ ]
o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr™ version
8.0.0
[junit4] 2> 3862138 INFO
(TEST-ComputePlanActionTest.testNodeAdded-seed#[4324EF2CAA18D31F]) [ ]
o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 3862138 INFO
(TEST-ComputePlanActionTest.testNodeAdded-seed#[4324EF2CAA18D31F]) [ ]
o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 3862138 INFO
(TEST-ComputePlanActionTest.testNodeAdded-seed#[4324EF2CAA18D31F]) [ ]
o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time:
2018-02-20T02:25:20.380Z
[junit4] 2> 3862140 INFO (zkConnectionManagerCallback-6392-thread-1) [
] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 3862141 INFO
(TEST-ComputePlanActionTest.testNodeAdded-seed#[4324EF2CAA18D31F]) [ ]
o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 3862148 INFO
(TEST-ComputePlanActionTest.testNodeAdded-seed#[4324EF2CAA18D31F]) [ ]
o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:61117/solr
[junit4] 2> 3862150 INFO (zkConnectionManagerCallback-6396-thread-1) [
] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 3862153 INFO
(zkConnectionManagerCallback-6398-thread-1-processing-n:127.0.0.1:55048_solr)
[n:127.0.0.1:55048_solr ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 3862163 INFO
(TEST-ComputePlanActionTest.testNodeAdded-seed#[4324EF2CAA18D31F])
[n:127.0.0.1:55048_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (0) -> (1)
[junit4] 2> 3862167 INFO
(TEST-ComputePlanActionTest.testNodeAdded-seed#[4324EF2CAA18D31F])
[n:127.0.0.1:55048_solr ] o.a.s.c.Overseer Overseer (id=null) closing
[junit4] 2> 3862170 INFO
(TEST-ComputePlanActionTest.testNodeAdded-seed#[4324EF2CAA18D31F])
[n:127.0.0.1:55048_solr ] o.a.s.c.ZkController Register node as live in
ZooKeeper:/live_nodes/127.0.0.1:55048_solr
[junit4] 2> 3862171 DEBUG
(OverseerStateUpdate-72228692014661635-127.0.0.1:38925_solr-n_0000000000)
[n:127.0.0.1:38925_solr ] o.a.s.c.Overseer processMessage: queueSize: 1,
message = {
[junit4] 2> "operation":"downnode",
[junit4] 2> "node_name":"127.0.0.1:55048_solr"} current state version: 0
[junit4] 2> 3862171 DEBUG
(OverseerStateUpdate-72228692014661635-127.0.0.1:38925_solr-n_0000000000)
[n:127.0.0.1:38925_solr ] o.a.s.c.o.NodeMutator DownNode state invoked for
node: 127.0.0.1:55048_solr
[junit4] 2> 3862172 INFO
(zkCallback-6380-thread-1-processing-n:127.0.0.1:38925_solr)
[n:127.0.0.1:38925_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (1) -> (2)
[junit4] 2> 3862173 INFO (zkCallback-6388-thread-1) [ ]
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
[junit4] 2> 3862173 INFO (zkCallback-6388-thread-2) [ ]
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
[junit4] 2> 3862173 INFO
(zkCallback-6397-thread-1-processing-n:127.0.0.1:55048_solr)
[n:127.0.0.1:55048_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (1) -> (2)
[junit4] 2> 3862239 INFO
(TEST-ComputePlanActionTest.testNodeAdded-seed#[4324EF2CAA18D31F])
[n:127.0.0.1:55048_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for
'solr_55048.solr.node' (registry 'solr.node') enabled at server:
com.sun.jmx.mbeanserver.JmxMBeanServer@68ced282
[junit4] 2> 3862246 INFO
(TEST-ComputePlanActionTest.testNodeAdded-seed#[4324EF2CAA18D31F])
[n:127.0.0.1:55048_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for
'solr_55048.solr.jvm' (registry 'solr.jvm') enabled at server:
com.sun.jmx.mbeanserver.JmxMBeanServer@68ced282
[junit4] 2> 3862247 INFO
(TEST-ComputePlanActionTest.testNodeAdded-seed#[4324EF2CAA18D31F])
[n:127.0.0.1:55048_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for
'solr_55048.solr.jetty' (registry 'solr.jetty') enabled at server:
com.sun.jmx.mbeanserver.JmxMBeanServer@68ced282
[junit4] 2> 3862248 INFO
(TEST-ComputePlanActionTest.testNodeAdded-seed#[4324EF2CAA18D31F])
[n:127.0.0.1:55048_solr ] o.a.s.c.CorePropertiesLocator Found 0 core
definitions underneath
/export/home/jenkins/workspace/Lucene-Solr-master-Solaris/solr/build/solr-core/test/J0/temp/solr.cloud.autoscaling.ComputePlanActionTest_4324EF2CAA18D31F-001/tempDir-001/node2/.
[junit4] 2> 3862677 DEBUG (ScheduledTrigger-12741-thread-2)
[n:127.0.0.1:38925_solr ] o.a.s.c.a.NodeAddedTrigger Running
NodeAddedTrigger node_added_trigger
[junit4] 2> 3862677 DEBUG (ScheduledTrigger-12741-thread-2)
[n:127.0.0.1:38925_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 2
[junit4] 2> 3862677 DEBUG (ScheduledTrigger-12741-thread-2)
[n:127.0.0.1:38925_solr ] o.a.s.c.a.NodeAddedTrigger Tracking new node:
127.0.0.1:55048_solr at time 2610752371691143
[junit4] 2> 3862678 INFO
(OverseerCollectionConfigSetProcessor-72228692014661635-127.0.0.1:38925_solr-n_0000000000)
[n:127.0.0.1:38925_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> 3863679 DEBUG (ScheduledTrigger-12741-thread-2)
[n:127.0.0.1:38925_solr ] o.a.s.c.a.NodeAddedTrigger Running
NodeAddedTrigger node_added_trigger
[junit4] 2> 3863679 DEBUG (ScheduledTrigger-12741-thread-2)
[n:127.0.0.1:38925_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 2
[junit4] 2> 3863679 DEBUG (ScheduledTrigger-12741-thread-2)
[n:127.0.0.1:38925_solr ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger
node_added_trigger firing registered processor for nodes:
[127.0.0.1:55048_solr] added at times [2610752371691143], now=2610753373949473
[junit4] 2> 3863680 DEBUG (ScheduledTrigger-12741-thread-2)
[n:127.0.0.1:38925_solr ] o.a.s.c.a.ScheduledTriggers ++++++++ Cooldown
inactive - processing event: {
[junit4] 2> "id":"9467727b60e87T3r6j706tidzw0b8wjy2i0cs3i",
[junit4] 2> "source":"node_added_trigger",
[junit4] 2> "eventTime":2610752371691143,
[junit4] 2> "eventType":"NODEADDED",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[2610752371691143],
[junit4] 2> "nodeNames":["127.0.0.1:55048_solr"]}}
[junit4] 2> 3863680 DEBUG (ScheduledTrigger-12741-thread-2)
[n:127.0.0.1:38925_solr ] o.a.s.c.a.ScheduledTriggers Pausing all triggers:
[node_added_trigger]
[junit4] 2> 3863681 INFO (ScheduledTrigger-12741-thread-2)
[n:127.0.0.1:38925_solr ] o.a.s.c.a.SystemLogListener Collection .system
does not exist, disabling logging.
[junit4] 2> 3863682 DEBUG
(AutoscalingActionExecutor-12742-thread-1-processing-n:127.0.0.1:38925_solr)
[n:127.0.0.1:38925_solr ] o.a.s.c.a.ScheduledTriggers -- processing actions
for {
[junit4] 2> "id":"9467727b60e87T3r6j706tidzw0b8wjy2i0cs3i",
[junit4] 2> "source":"node_added_trigger",
[junit4] 2> "eventTime":2610752371691143,
[junit4] 2> "eventType":"NODEADDED",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[2610752371691143],
[junit4] 2> "_enqueue_time_":2610753374627653,
[junit4] 2> "nodeNames":["127.0.0.1:55048_solr"]}}
[junit4] 2> 3863682 DEBUG
(AutoscalingActionExecutor-12742-thread-1-processing-n:127.0.0.1:38925_solr)
[n:127.0.0.1:38925_solr ] o.a.s.c.a.ComputePlanAction -- processing event: {
[junit4] 2> "id":"9467727b60e87T3r6j706tidzw0b8wjy2i0cs3i",
[junit4] 2> "source":"node_added_trigger",
[junit4] 2> "eventTime":2610752371691143,
[junit4] 2> "eventType":"NODEADDED",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[2610752371691143],
[junit4] 2> "_enqueue_time_":2610753374627653,
[junit4] 2> "nodeNames":["127.0.0.1:55048_solr"]}} with context
properties: {BEFORE_ACTION=[compute_plan]}
[junit4] 2> 3863683 INFO (qtp2092840606-33575) [n:127.0.0.1:38925_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> 3863685 INFO (qtp2092840606-33574) [n:127.0.0.1:38925_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> 3863688 INFO (qtp365583514-33623) [n:127.0.0.1:55048_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> 3863689 INFO
(AutoscalingActionExecutor-12742-thread-1-processing-n:127.0.0.1:38925_solr)
[n:127.0.0.1:38925_solr ] o.a.s.c.a.ComputePlanAction Computed Plan:
action=MOVEREPLICA&collection=testNodeAdded&targetNode=127.0.0.1:55048_solr&inPlaceMove=true&replica=core_node3
[junit4] 2> 3863689 INFO
(AutoscalingActionExecutor-12742-thread-1-processing-n:127.0.0.1:38925_solr)
[n:127.0.0.1:38925_solr ] o.a.s.c.s.c.a.PolicyHelper returnSession,
curr-time 2610753383 sessionWrapper.createTime 2610753383062541,
this.sessionWrapper.createTime 2610753383062541
[junit4] 2> 3863689 DEBUG
(TEST-ComputePlanActionTest.testNodeAdded-seed#[4324EF2CAA18D31F]) [ ]
o.a.s.c.a.ComputePlanActionTest -------------_ FINAL STATE --------------
[junit4] 2> 3863691 DEBUG
(AutoscalingActionExecutor-12742-thread-1-processing-n:127.0.0.1:38925_solr)
[n:127.0.0.1:38925_solr ] o.a.s.c.a.ScheduledTriggers Resuming trigger:
node_added_trigger after 5000ms
[junit4] 2> 3863691 DEBUG
(AutoscalingActionExecutor-12742-thread-1-processing-n:127.0.0.1:38925_solr)
[n:127.0.0.1:38925_solr ] o.a.s.c.a.ScheduledTriggers -- processing took 9
ms for event id=9467727b60e87T3r6j706tidzw0b8wjy2i0cs3i
[junit4] 2> 3863691 INFO (qtp2092840606-33575) [n:127.0.0.1:38925_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> 3863692 DEBUG
(TEST-ComputePlanActionTest.testNodeAdded-seed#[4324EF2CAA18D31F]) [ ]
o.a.s.c.a.ComputePlanActionTest * Node values: 127.0.0.1:38925_solr
[junit4] 2> {
[junit4] 2> "node":"127.0.0.1:38925_solr",
[junit4] 2> "cores":2,
[junit4] 2> "port":"38925",
[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":12.304348945617676}
[junit4] 2> 3863694 INFO (qtp365583514-33627) [n:127.0.0.1:55048_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> 3863694 DEBUG
(TEST-ComputePlanActionTest.testNodeAdded-seed#[4324EF2CAA18D31F]) [ ]
o.a.s.c.a.ComputePlanActionTest * Node values: 127.0.0.1:55048_solr
[junit4] 2> {
[junit4] 2> "node":"127.0.0.1:55048_solr",
[junit4] 2> "cores":0,
[junit4] 2> "port":"55048",
[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":12.304348945617676}
[junit4] 2> 3863694 DEBUG
(TEST-ComputePlanActionTest.testNodeAdded-seed#[4324EF2CAA18D31F]) [ ]
o.a.s.c.a.ComputePlanActionTest * Live nodes: [127.0.0.1:38925_solr,
127.0.0.1:55048_solr]
[junit4] 2> 3863695 DEBUG
(TEST-ComputePlanActionTest.testNodeAdded-seed#[4324EF2CAA18D31F]) [ ]
o.a.s.c.a.ComputePlanActionTest * Collection testNodeAdded state:
DocCollection(testNodeAdded//collections/testNodeAdded/state.json/6)={
[junit4] 2> "pullReplicas":"0",
[junit4] 2> "replicationFactor":"2",
[junit4] 2> "shards":{"shard1":{
[junit4] 2> "range":"80000000-7fffffff",
[junit4] 2> "state":"active",
[junit4] 2> "replicas":{
[junit4] 2> "core_node3":{
[junit4] 2> "core":"testNodeAdded_shard1_replica_n1",
[junit4] 2> "base_url":"http://127.0.0.1:38925/solr";,
[junit4] 2> "node_name":"127.0.0.1:38925_solr",
[junit4] 2> "state":"active",
[junit4] 2> "type":"NRT"},
[junit4] 2> "core_node4":{
[junit4] 2> "core":"testNodeAdded_shard1_replica_n2",
[junit4] 2> "base_url":"http://127.0.0.1:38925/solr";,
[junit4] 2> "node_name":"127.0.0.1:38925_solr",
[junit4] 2> "state":"active",
[junit4] 2> "type":"NRT",
[junit4] 2> "leader":"true"}}}},
[junit4] 2> "router":{"name":"compositeId"},
[junit4] 2> "maxShardsPerNode":"1",
[junit4] 2> "autoAddReplicas":"false",
[junit4] 2> "nrtReplicas":"2",
[junit4] 2> "tlogReplicas":"0"}
[junit4] 2> 3863695 INFO
(TEST-ComputePlanActionTest.testNodeAdded-seed#[4324EF2CAA18D31F]) [ ]
o.a.s.SolrTestCaseJ4 ###Ending testNodeAdded
[junit4] 2> 3863713 INFO
(TEST-ComputePlanActionTest.testNodeLost-seed#[4324EF2CAA18D31F]) [ ]
o.a.s.SolrTestCaseJ4 ###Starting testNodeLost
[junit4] 2> 3863714 DEBUG
(zkCallback-6380-thread-1-processing-n:127.0.0.1:38925_solr)
[n:127.0.0.1:38925_solr ] o.a.s.c.a.OverseerTriggerThread Refreshing
/autoscaling.json with znode version 8
[junit4] 2> 3863714 DEBUG
(OverseerAutoScalingTriggerThread-72228692014661635-127.0.0.1:38925_solr-n_0000000000)
[n:127.0.0.1:38925_solr ] o.a.s.c.a.OverseerTriggerThread Processed trigger
updates upto znodeVersion 8
[junit4] 2> 3863715 INFO
(TEST-ComputePlanActionTest.testNodeLost-seed#[4324EF2CAA18D31F]) [ ]
o.e.j.s.AbstractConnector Stopped
ServerConnector@15eebe3c{HTTP/1.1,[http/1.1]}{127.0.0.1:0}
[junit4] 2> 3863716 INFO
(TEST-ComputePlanActionTest.testNodeLost-seed#[4324EF2CAA18D31F]) [ ]
o.a.s.c.CoreContainer Shutting down CoreContainer instance=1096261037
[junit4] 2> 3863716 DEBUG
(OverseerAutoScalingTriggerThread-72228692014661635-127.0.0.1:38925_solr-n_0000000000)
[n:127.0.0.1:38925_solr ] o.a.s.c.a.OverseerTriggerThread -- clean old
nodeLost markers
[junit4] 2> 3863716 INFO
(TEST-ComputePlanActionTest.testNodeLost-seed#[4324EF2CAA18D31F]) [ ]
o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.node,
tag=null
[junit4] 2> 3863717 INFO
(TEST-ComputePlanActionTest.testNodeLost-seed#[4324EF2CAA18D31F]) [ ]
o.a.s.m.r.SolrJmxReporter Closing reporter
[org.apache.solr.metrics.reporters.SolrJmxReporter@13ef9a89: rootName =
solr_38925, domain = solr.node, service url = null, agent id = null] for
registry solr.node / com.codahale.metrics.MetricRegistry@55cce09d
[junit4] 2> 3863717 DEBUG
(OverseerAutoScalingTriggerThread-72228692014661635-127.0.0.1:38925_solr-n_0000000000)
[n:127.0.0.1:38925_solr ] o.a.s.c.a.OverseerTriggerThread -- clean old
nodeAdded markers
[junit4] 2> 3863717 DEBUG
(OverseerAutoScalingTriggerThread-72228692014661635-127.0.0.1:38925_solr-n_0000000000)
[n:127.0.0.1:38925_solr ] o.a.s.c.a.OverseerTriggerThread Current
znodeVersion 8, lastZnodeVersion 8
[junit4] 2> 3863721 INFO
(TEST-ComputePlanActionTest.testNodeLost-seed#[4324EF2CAA18D31F]) [ ]
o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jvm,
tag=null
[junit4] 2> 3863721 INFO
(TEST-ComputePlanActionTest.testNodeLost-seed#[4324EF2CAA18D31F]) [ ]
o.a.s.m.r.SolrJmxReporter Closing reporter
[org.apache.solr.metrics.reporters.SolrJmxReporter@1e29036: rootName =
solr_38925, domain = solr.jvm, service url = null, agent id = null] for
registry solr.jvm / com.codahale.metrics.MetricRegistry@55fbcd57
[junit4] 2> 3863725 INFO
(TEST-ComputePlanActionTest.testNodeLost-seed#[4324EF2CAA18D31F]) [ ]
o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jetty,
tag=null
[junit4] 2> 3863725 INFO
(TEST-ComputePlanActionTest.testNodeLost-seed#[4324EF2CAA18D31F]) [ ]
o.a.s.m.r.SolrJmxReporter Closing reporter
[org.apache.solr.metrics.reporters.SolrJmxReporter@6f1e7c5c: rootName =
solr_38925, domain = solr.jetty, service url = null, agent id = null] for
registry solr.jetty / com.codahale.metrics.MetricRegistry@483bdb63
[junit4] 2> 3863728 INFO
(TEST-ComputePlanActionTest.testNodeLost-seed#[4324EF2CAA18D31F]) [ ]
o.a.s.c.ZkController Remove node as live in
ZooKeeper:/live_nodes/127.0.0.1:38925_solr
[junit4] 2> 3863729 DEBUG
(OverseerStateUpdate-72228692014661635-127.0.0.1:38925_solr-n_0000000000)
[n:127.0.0.1:38925_solr ] o.a.s.c.Overseer processMessage: queueSize: 1,
message = {
[junit4] 2> "operation":"downnode",
[junit4] 2> "node_name":"127.0.0.1:38925_solr"} current state version: 0
[junit4] 2> 3863729 DEBUG
(OverseerStateUpdate-72228692014661635-127.0.0.1:38925_solr-n_0000000000)
[n:127.0.0
[...truncated too long message...]
eper.stopScavenging Stopped scavenging
[junit4] 2> 49313 T12 oejs.AbstractConnector.doStop Stopped
ServerConnector@4fa39e5e{HTTP/1.1,[http/1.1]}{127.0.0.1:0}
[junit4] 2> 49313 T12 oasc.CoreContainer.shutdown Shutting down
CoreContainer instance=1334190035
[junit4] 2> 49313 T12 oasm.SolrMetricManager.closeReporters Closing metric
reporters for registry=solr.node, tag=null
[junit4] 2> 49314 T12 oasm.SolrMetricManager.closeReporters Closing metric
reporters for registry=solr.jvm, tag=null
[junit4] 2> 49314 T12 oasm.SolrMetricManager.closeReporters Closing metric
reporters for registry=solr.jetty, tag=null
[junit4] 2> 49319 T204 x:x:collection1 oasc.SolrCore.close [collection1]
CLOSING SolrCore org.apache.solr.core.SolrCore@5a987012
[junit4] 2> 49320 T204 x:x:collection1
oasm.SolrMetricManager.closeReporters Closing metric reporters for
registry=solr.core.collection1, tag=1519939602
[junit4] 2> 49326 T12 oejsh.ContextHandler.doStop Stopped
o.e.j.s.ServletContextHandler@55afd82e{/,null,UNAVAILABLE}
[junit4] 2> 49326 T12 oejss.HouseKeeper.stopScavenging Stopped scavenging
[junit4] 2> 49332 T12 oejs.AbstractConnector.doStop Stopped
ServerConnector@74a8fa9c{HTTP/1.1,[http/1.1]}{127.0.0.1:0}
[junit4] 2> 49333 T12 oasc.CoreContainer.shutdown Shutting down
CoreContainer instance=1596671301
[junit4] 2> 49334 T12 oasm.SolrMetricManager.closeReporters Closing metric
reporters for registry=solr.node, tag=null
[junit4] 2> 49334 T12 oasm.SolrMetricManager.closeReporters Closing metric
reporters for registry=solr.jvm, tag=null
[junit4] 2> 49334 T12 oasm.SolrMetricManager.closeReporters Closing metric
reporters for registry=solr.jetty, tag=null
[junit4] 2> 49336 T206 x:x:collection1 oasc.SolrCore.close [collection1]
CLOSING SolrCore org.apache.solr.core.SolrCore@352e7052
[junit4] 2> 49337 T206 x:x:collection1
oasm.SolrMetricManager.closeReporters Closing metric reporters for
registry=solr.core.collection1, tag=892235858
[junit4] 2> 49346 T12 oejsh.ContextHandler.doStop Stopped
o.e.j.s.ServletContextHandler@4edd8a5b{/,null,UNAVAILABLE}
[junit4] 2> 49346 T12 oejss.HouseKeeper.stopScavenging Stopped scavenging
[junit4] 2> 49353 T12 oejs.AbstractConnector.doStop Stopped
ServerConnector@24261373{HTTP/1.1,[http/1.1]}{127.0.0.1:0}
[junit4] 2> 49354 T12 oasc.CoreContainer.shutdown Shutting down
CoreContainer instance=2093603989
[junit4] 2> 49354 T12 oasm.SolrMetricManager.closeReporters Closing metric
reporters for registry=solr.node, tag=null
[junit4] 2> 49355 T12 oasm.SolrMetricManager.closeReporters Closing metric
reporters for registry=solr.jvm, tag=null
[junit4] 2> 49355 T12 oasm.SolrMetricManager.closeReporters Closing metric
reporters for registry=solr.jetty, tag=null
[junit4] 2> 49357 T208 x:x:collection1 oasc.SolrCore.close [collection1]
CLOSING SolrCore org.apache.solr.core.SolrCore@2f1a2630
[junit4] 2> 49357 T208 x:x:collection1
oasm.SolrMetricManager.closeReporters Closing metric reporters for
registry=solr.core.collection1, tag=790242864
[junit4] 2> 49362 T12 oejsh.ContextHandler.doStop Stopped
o.e.j.s.ServletContextHandler@66977b75{/,null,UNAVAILABLE}
[junit4] 2> 49363 T12 oejss.HouseKeeper.stopScavenging Stopped scavenging
[junit4] 2> 49373 T12 oas.SolrTestCaseJ4.clearObjectTrackerAndCheckEmpty
------------------------------------------------------- Done waiting for
tracked resources to be released
[junit4] 2> Feb 20, 2018 2:48:14 AM
com.carrotsearch.randomizedtesting.ThreadLeakControl checkThreadLeaks
[junit4] 2> WARNING: Will linger awaiting termination of 1 leaked
thread(s).
[junit4] 2> Feb 20, 2018 2:48:34 AM
com.carrotsearch.randomizedtesting.ThreadLeakControl checkThreadLeaks
[junit4] 2> SEVERE: 1 thread leaked from SUITE scope at
org.apache.solr.handler.clustering.DistributedClusteringComponentTest:
[junit4] 2> 1) Thread[id=37, name=qtp1278777971-37,
state=TIMED_WAITING, group=TGRP-DistributedClusteringComponentTest]
[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 20, 2018 2:48:34 AM
com.carrotsearch.randomizedtesting.ThreadLeakControl tryToInterruptAll
[junit4] 2> INFO: Starting to interrupt leaked threads:
[junit4] 2> 1) Thread[id=37, name=qtp1278777971-37,
state=TIMED_WAITING, group=TGRP-DistributedClusteringComponentTest]
[junit4] 2> Feb 20, 2018 2:48:37 AM
com.carrotsearch.randomizedtesting.ThreadLeakControl tryToInterruptAll
[junit4] 2> SEVERE: There are still zombie threads that couldn't be
terminated:
[junit4] 2> 1) Thread[id=37, name=qtp1278777971-37,
state=TIMED_WAITING, group=TGRP-DistributedClusteringComponentTest]
[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):
{snippet=TestBloomFilteredLucenePostings(BloomFilteringPostingsFormat(Lucene50(blocksize=128))),
id=FSTOrd50,
text=TestBloomFilteredLucenePostings(BloomFilteringPostingsFormat(Lucene50(blocksize=128))),
title=FST50, url=FSTOrd50}, docValues:{}, maxPointsInLeafNode=1083,
maxMBSortInHeap=6.1275688775296855,
sim=Asserting(org.apache.lucene.search.similarities.AssertingSimilarity@4227ee9a),
locale=ja, timezone=Asia/Ujung_Pandang
[junit4] 2> NOTE: SunOS 5.11 amd64/Oracle Corporation 1.8.0_152
(64-bit)/cpus=3,threads=2,free=95763488,total=188743680
[junit4] 2> NOTE: All tests run in this JVM:
[DistributedClusteringComponentTest]
[junit4] 2> NOTE: reproduce with: ant test
-Dtestcase=DistributedClusteringComponentTest -Dtests.seed=8AEF5CD4F3FBC58
-Dtests.slow=true -Dtests.locale=ja -Dtests.timezone=Asia/Ujung_Pandang
-Dtests.asserts=true -Dtests.file.encoding=UTF-8
[junit4] ERROR 0.00s J0 | DistributedClusteringComponentTest (suite) <<<
[junit4] > Throwable #1:
com.carrotsearch.randomizedtesting.ThreadLeakError: 1 thread leaked from SUITE
scope at org.apache.solr.handler.clustering.DistributedClusteringComponentTest:
[junit4] > 1) Thread[id=37, name=qtp1278777971-37,
state=TIMED_WAITING, group=TGRP-DistributedClusteringComponentTest]
[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([8AEF5CD4F3FBC58]:0)Throwable #2:
com.carrotsearch.randomizedtesting.ThreadLeakError: There are still zombie
threads that couldn't be terminated:
[junit4] > 1) Thread[id=37, name=qtp1278777971-37,
state=TIMED_WAITING, group=TGRP-DistributedClusteringComponentTest]
[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([8AEF5CD4F3FBC58]:0)
[junit4] Completed [3/3 (1!)] on J0 in 73.12s, 1 test, 2 errors <<< FAILURES!
[...truncated 44710 lines...]
---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscr...@lucene.apache.org
For additional commands, e-mail: dev-h...@lucene.apache.org
