Build: https://builds.apache.org/job/Lucene-Solr-Tests-master/2311/
4 tests failed.
FAILED:
junit.framework.TestSuite.org.apache.solr.handler.dataimport.TestSolrEntityProcessorEndToEnd
Error Message:
1 thread leaked from SUITE scope at
org.apache.solr.handler.dataimport.TestSolrEntityProcessorEndToEnd: 1)
Thread[id=120, name=qtp1706926551-120, state=TIMED_WAITING,
group=TGRP-TestSolrEntityProcessorEndToEnd] 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.dataimport.TestSolrEntityProcessorEndToEnd:
1) Thread[id=120, name=qtp1706926551-120, state=TIMED_WAITING,
group=TGRP-TestSolrEntityProcessorEndToEnd]
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([A746474AAE52596C]:0)
FAILED:
junit.framework.TestSuite.org.apache.solr.handler.dataimport.TestSolrEntityProcessorEndToEnd
Error Message:
There are still zombie threads that couldn't be terminated: 1)
Thread[id=120, name=qtp1706926551-120, state=TIMED_WAITING,
group=TGRP-TestSolrEntityProcessorEndToEnd] 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=120, name=qtp1706926551-120, state=TIMED_WAITING,
group=TGRP-TestSolrEntityProcessorEndToEnd]
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([A746474AAE52596C]: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([81786C5B037118A0:B1B88DD98B03F9FC]: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)
FAILED:
org.apache.solr.cloud.autoscaling.TriggerIntegrationTest.testSetProperties
Error Message:
Expected 8 triggers but found: [x0, x1, x2, x3, x4, x5, x6] expected:<8> but
was:<7>
Stack Trace:
java.lang.AssertionError: Expected 8 triggers but found: [x0, x1, x2, x3, x4,
x5, x6] expected:<8> but was:<7>
at
__randomizedtesting.SeedInfo.seed([81786C5B037118A0:EA1CBB12B05C8D24]:0)
at org.junit.Assert.fail(Assert.java:93)
at org.junit.Assert.failNotEquals(Assert.java:647)
at org.junit.Assert.assertEquals(Assert.java:128)
at org.junit.Assert.assertEquals(Assert.java:472)
at
org.apache.solr.cloud.autoscaling.TriggerIntegrationTest.testSetProperties(TriggerIntegrationTest.java:1322)
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 12505 lines...]
[junit4] Suite: org.apache.solr.cloud.autoscaling.ComputePlanActionTest
[junit4] 2> Creating dataDir:
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/solr/build/solr-core/test/J1/temp/solr.cloud.autoscaling.ComputePlanActionTest_81786C5B037118A0-001/init-core-data-001
[junit4] 2> 666957 WARN
(SUITE-ComputePlanActionTest-seed#[81786C5B037118A0]-worker) [ ]
o.a.s.SolrTestCaseJ4 startTrackingSearchers: numOpens=1 numCloses=1
[junit4] 2> 666957 INFO
(SUITE-ComputePlanActionTest-seed#[81786C5B037118A0]-worker) [ ]
o.a.s.SolrTestCaseJ4 Using PointFields (NUMERIC_POINTS_SYSPROP=true)
w/NUMERIC_DOCVALUES_SYSPROP=false
[junit4] 2> 666958 INFO
(SUITE-ComputePlanActionTest-seed#[81786C5B037118A0]-worker) [ ]
o.a.s.SolrTestCaseJ4 Randomized ssl (false) and clientAuth (true) via:
@org.apache.solr.util.RandomizeSSL(reason=, ssl=NaN, value=NaN, clientAuth=NaN)
[junit4] 2> 666958 INFO
(SUITE-ComputePlanActionTest-seed#[81786C5B037118A0]-worker) [ ]
o.a.s.SolrTestCaseJ4 SecureRandom sanity checks:
test.solr.allowed.securerandom=null & java.security.egd=file:/dev/./urandom
[junit4] 2> 666959 INFO
(SUITE-ComputePlanActionTest-seed#[81786C5B037118A0]-worker) [ ]
o.a.s.c.MiniSolrCloudCluster Starting cluster of 1 servers in
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/solr/build/solr-core/test/J1/temp/solr.cloud.autoscaling.ComputePlanActionTest_81786C5B037118A0-001/tempDir-001
[junit4] 2> 666959 INFO
(SUITE-ComputePlanActionTest-seed#[81786C5B037118A0]-worker) [ ]
o.a.s.c.ZkTestServer STARTING ZK TEST SERVER
[junit4] 2> 666959 INFO (Thread-2135) [ ] o.a.s.c.ZkTestServer client
port:0.0.0.0/0.0.0.0:0
[junit4] 2> 666959 INFO (Thread-2135) [ ] o.a.s.c.ZkTestServer
Starting server
[junit4] 2> 666965 ERROR (Thread-2135) [ ] 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> 667059 INFO
(SUITE-ComputePlanActionTest-seed#[81786C5B037118A0]-worker) [ ]
o.a.s.c.ZkTestServer start zk server on port:37378
[junit4] 2> 667061 INFO (zkConnectionManagerCallback-1561-thread-1) [
] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 667064 INFO (jetty-launcher-1558-thread-1) [ ]
o.e.j.s.Server jetty-9.4.8.v20171121, build timestamp:
2017-11-21T16:27:37-05:00, git hash: 82b8fb23f757335bb3329d540ce37a2a2615f0a8
[junit4] 2> 667069 INFO (jetty-launcher-1558-thread-1) [ ]
o.e.j.s.session DefaultSessionIdManager workerName=node0
[junit4] 2> 667069 INFO (jetty-launcher-1558-thread-1) [ ]
o.e.j.s.session No SessionScavenger set, using defaults
[junit4] 2> 667069 INFO (jetty-launcher-1558-thread-1) [ ]
o.e.j.s.session Scavenging every 600000ms
[junit4] 2> 667069 INFO (jetty-launcher-1558-thread-1) [ ]
o.e.j.s.h.ContextHandler Started
o.e.j.s.ServletContextHandler@43182e94{/solr,null,AVAILABLE}
[junit4] 2> 667069 INFO (jetty-launcher-1558-thread-1) [ ]
o.e.j.s.AbstractConnector Started
ServerConnector@54bbbe13{HTTP/1.1,[http/1.1]}{127.0.0.1:42838}
[junit4] 2> 667069 INFO (jetty-launcher-1558-thread-1) [ ]
o.e.j.s.Server Started @668826ms
[junit4] 2> 667069 INFO (jetty-launcher-1558-thread-1) [ ]
o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr,
hostPort=42838}
[junit4] 2> 667070 ERROR (jetty-launcher-1558-thread-1) [ ]
o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be
missing or incomplete.
[junit4] 2> 667070 INFO (jetty-launcher-1558-thread-1) [ ]
o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version
8.0.0
[junit4] 2> 667070 INFO (jetty-launcher-1558-thread-1) [ ]
o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 667070 INFO (jetty-launcher-1558-thread-1) [ ]
o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 667070 INFO (jetty-launcher-1558-thread-1) [ ]
o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time:
2018-02-11T13:29:58.622Z
[junit4] 2> 667078 INFO (zkConnectionManagerCallback-1563-thread-1) [
] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 667078 INFO (jetty-launcher-1558-thread-1) [ ]
o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 667085 INFO (jetty-launcher-1558-thread-1) [ ]
o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:37378/solr
[junit4] 2> 667088 INFO (zkConnectionManagerCallback-1567-thread-1) [
] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 667093 INFO
(zkConnectionManagerCallback-1569-thread-1-processing-n:127.0.0.1:42838_solr)
[n:127.0.0.1:42838_solr ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 667137 INFO (jetty-launcher-1558-thread-1)
[n:127.0.0.1:42838_solr ] o.a.s.c.Overseer Overseer (id=null) closing
[junit4] 2> 667138 INFO (jetty-launcher-1558-thread-1)
[n:127.0.0.1:42838_solr ] o.a.s.c.OverseerElectionContext I am going to be
the leader 127.0.0.1:42838_solr
[junit4] 2> 667138 INFO (jetty-launcher-1558-thread-1)
[n:127.0.0.1:42838_solr ] o.a.s.c.Overseer Overseer
(id=73277068866420739-127.0.0.1:42838_solr-n_0000000000) starting
[junit4] 2> 667143 DEBUG
(OverseerStateUpdate-73277068866420739-127.0.0.1:42838_solr-n_0000000000)
[n:127.0.0.1:42838_solr ] o.a.s.c.Overseer Starting to work on the main queue
[junit4] 2> 667149 INFO (jetty-launcher-1558-thread-1)
[n:127.0.0.1:42838_solr ] o.a.s.c.ZkController Register node as live in
ZooKeeper:/live_nodes/127.0.0.1:42838_solr
[junit4] 2> 667157 INFO
(zkCallback-1568-thread-1-processing-n:127.0.0.1:42838_solr)
[n:127.0.0.1:42838_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (0) -> (1)
[junit4] 2> 667157 DEBUG
(OverseerAutoScalingTriggerThread-73277068866420739-127.0.0.1:42838_solr-n_0000000000)
[n:127.0.0.1:42838_solr ] o.a.s.c.a.OverseerTriggerThread Adding
.autoAddReplicas trigger
[junit4] 2> 667158 DEBUG
(OverseerAutoScalingTriggerThread-73277068866420739-127.0.0.1:42838_solr-n_0000000000)
[n:127.0.0.1:42838_solr ] o.a.s.c.a.OverseerTriggerThread Refreshing
/autoscaling.json with znode version 1
[junit4] 2> 667159 DEBUG
(OverseerAutoScalingTriggerThread-73277068866420739-127.0.0.1:42838_solr-n_0000000000)
[n:127.0.0.1:42838_solr ] o.a.s.c.a.NodeLostTrigger Initial livenodes:
[127.0.0.1:42838_solr]
[junit4] 2> 667159 DEBUG
(OverseerAutoScalingTriggerThread-73277068866420739-127.0.0.1:42838_solr-n_0000000000)
[n:127.0.0.1:42838_solr ] o.a.s.c.a.OverseerTriggerThread Current
znodeVersion 1, lastZnodeVersion -1
[junit4] 2> 667159 DEBUG
(OverseerAutoScalingTriggerThread-73277068866420739-127.0.0.1:42838_solr-n_0000000000)
[n:127.0.0.1:42838_solr ] o.a.s.c.a.OverseerTriggerThread Processed trigger
updates upto znodeVersion 1
[junit4] 2> 667160 DEBUG
(OverseerAutoScalingTriggerThread-73277068866420739-127.0.0.1:42838_solr-n_0000000000)
[n:127.0.0.1:42838_solr ] o.a.s.c.a.OverseerTriggerThread -- clean old
nodeAdded markers
[junit4] 2> 667160 DEBUG
(OverseerAutoScalingTriggerThread-73277068866420739-127.0.0.1:42838_solr-n_0000000000)
[n:127.0.0.1:42838_solr ] o.a.s.c.a.OverseerTriggerThread Current
znodeVersion 1, lastZnodeVersion 1
[junit4] 2> 667161 DEBUG (ScheduledTrigger-2607-thread-1)
[n:127.0.0.1:42838_solr ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger:
.auto_add_replicas with currently live nodes: 1
[junit4] 2> 667225 INFO (jetty-launcher-1558-thread-1)
[n:127.0.0.1:42838_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for
'solr_42838.solr.node' (registry 'solr.node') enabled at server:
com.sun.jmx.mbeanserver.JmxMBeanServer@1ac5a0ba
[junit4] 2> 667232 INFO (jetty-launcher-1558-thread-1)
[n:127.0.0.1:42838_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for
'solr_42838.solr.jvm' (registry 'solr.jvm') enabled at server:
com.sun.jmx.mbeanserver.JmxMBeanServer@1ac5a0ba
[junit4] 2> 667232 INFO (jetty-launcher-1558-thread-1)
[n:127.0.0.1:42838_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for
'solr_42838.solr.jetty' (registry 'solr.jetty') enabled at server:
com.sun.jmx.mbeanserver.JmxMBeanServer@1ac5a0ba
[junit4] 2> 667233 INFO (jetty-launcher-1558-thread-1)
[n:127.0.0.1:42838_solr ] o.a.s.c.CorePropertiesLocator Found 0 core
definitions underneath
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/solr/build/solr-core/test/J1/temp/solr.cloud.autoscaling.ComputePlanActionTest_81786C5B037118A0-001/tempDir-001/node1/.
[junit4] 2> 667255 INFO (zkConnectionManagerCallback-1573-thread-1) [
] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 667258 INFO (zkConnectionManagerCallback-1577-thread-1) [
] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 667259 INFO
(SUITE-ComputePlanActionTest-seed#[81786C5B037118A0]-worker) [ ]
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 667260 INFO
(SUITE-ComputePlanActionTest-seed#[81786C5B037118A0]-worker) [ ]
o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:37378/solr ready
[junit4] 2> 667276 INFO
(TEST-ComputePlanActionTest.testNodeAdded-seed#[81786C5B037118A0]) [ ]
o.a.s.SolrTestCaseJ4 ###Starting testNodeAdded
[junit4] 2> 667277 DEBUG
(zkCallback-1568-thread-1-processing-n:127.0.0.1:42838_solr)
[n:127.0.0.1:42838_solr ] o.a.s.c.a.OverseerTriggerThread Refreshing
/autoscaling.json with znode version 2
[junit4] 2> 667278 DEBUG
(OverseerAutoScalingTriggerThread-73277068866420739-127.0.0.1:42838_solr-n_0000000000)
[n:127.0.0.1:42838_solr ] o.a.s.c.a.OverseerTriggerThread Processed trigger
updates upto znodeVersion 2
[junit4] 2> 667279 INFO
(TEST-ComputePlanActionTest.testNodeAdded-seed#[81786C5B037118A0]) [ ]
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 667280 DEBUG
(OverseerAutoScalingTriggerThread-73277068866420739-127.0.0.1:42838_solr-n_0000000000)
[n:127.0.0.1:42838_solr ] o.a.s.c.a.OverseerTriggerThread -- clean old
nodeLost markers
[junit4] 2> 667280 DEBUG
(OverseerAutoScalingTriggerThread-73277068866420739-127.0.0.1:42838_solr-n_0000000000)
[n:127.0.0.1:42838_solr ] o.a.s.c.a.OverseerTriggerThread -- clean old
nodeAdded markers
[junit4] 2> 667281 DEBUG
(OverseerAutoScalingTriggerThread-73277068866420739-127.0.0.1:42838_solr-n_0000000000)
[n:127.0.0.1:42838_solr ] o.a.s.c.a.OverseerTriggerThread Current
znodeVersion 2, lastZnodeVersion 2
[junit4] 2> 667286 INFO (qtp1528890485-7224) [n:127.0.0.1:42838_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> 667289 DEBUG (qtp1528890485-7222) [n:127.0.0.1:42838_solr ]
o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
[junit4] 2> 667289 INFO (qtp1528890485-7222) [n:127.0.0.1:42838_solr ]
o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/autoscaling
params={wt=javabin&version=2} status=0 QTime=5
[junit4] 2> 667290 DEBUG
(zkCallback-1568-thread-1-processing-n:127.0.0.1:42838_solr)
[n:127.0.0.1:42838_solr ] o.a.s.c.a.OverseerTriggerThread Refreshing
/autoscaling.json with znode version 3
[junit4] 2> 667290 DEBUG
(OverseerAutoScalingTriggerThread-73277068866420739-127.0.0.1:42838_solr-n_0000000000)
[n:127.0.0.1:42838_solr ] o.a.s.c.a.OverseerTriggerThread Processed trigger
updates upto znodeVersion 3
[junit4] 2> 667290 DEBUG
(OverseerAutoScalingTriggerThread-73277068866420739-127.0.0.1:42838_solr-n_0000000000)
[n:127.0.0.1:42838_solr ] o.a.s.c.a.OverseerTriggerThread -- clean old
nodeLost markers
[junit4] 2> 667291 DEBUG
(OverseerAutoScalingTriggerThread-73277068866420739-127.0.0.1:42838_solr-n_0000000000)
[n:127.0.0.1:42838_solr ] o.a.s.c.a.OverseerTriggerThread -- clean old
nodeAdded markers
[junit4] 2> 667292 DEBUG
(OverseerAutoScalingTriggerThread-73277068866420739-127.0.0.1:42838_solr-n_0000000000)
[n:127.0.0.1:42838_solr ] o.a.s.c.a.OverseerTriggerThread Current
znodeVersion 3, lastZnodeVersion 3
[junit4] 2> 667293 INFO (qtp1528890485-7219) [n:127.0.0.1:42838_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> 667293 DEBUG (qtp1528890485-7220) [n:127.0.0.1:42838_solr ]
o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
[junit4] 2> 667294 INFO (qtp1528890485-7220) [n:127.0.0.1:42838_solr ]
o.a.s.s.HttpSolrCall [admin] webapp=null path=/cluster/autoscaling
params={wt=javabin&version=2} status=0 QTime=3
[junit4] 2> 667295 DEBUG
(zkCallback-1568-thread-1-processing-n:127.0.0.1:42838_solr)
[n:127.0.0.1:42838_solr ] o.a.s.c.a.OverseerTriggerThread Refreshing
/autoscaling.json with znode version 4
[junit4] 2> 667295 DEBUG
(OverseerAutoScalingTriggerThread-73277068866420739-127.0.0.1:42838_solr-n_0000000000)
[n:127.0.0.1:42838_solr ] o.a.s.c.a.OverseerTriggerThread Processed trigger
updates upto znodeVersion 4
[junit4] 2> 667295 DEBUG
(OverseerAutoScalingTriggerThread-73277068866420739-127.0.0.1:42838_solr-n_0000000000)
[n:127.0.0.1:42838_solr ] o.a.s.c.a.OverseerTriggerThread -- clean old
nodeLost markers
[junit4] 2> 667295 DEBUG
(OverseerAutoScalingTriggerThread-73277068866420739-127.0.0.1:42838_solr-n_0000000000)
[n:127.0.0.1:42838_solr ] o.a.s.c.a.OverseerTriggerThread -- clean old
nodeAdded markers
[junit4] 2> 667296 DEBUG
(OverseerAutoScalingTriggerThread-73277068866420739-127.0.0.1:42838_solr-n_0000000000)
[n:127.0.0.1:42838_solr ] o.a.s.c.a.OverseerTriggerThread Current
znodeVersion 4, lastZnodeVersion 4
[junit4] 2> 667296 INFO (qtp1528890485-7224) [n:127.0.0.1:42838_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> 667296 DEBUG (qtp1528890485-7221) [n:127.0.0.1:42838_solr ]
o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
[junit4] 2> 667297 INFO (qtp1528890485-7221) [n:127.0.0.1:42838_solr ]
o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/autoscaling
params={wt=javabin&version=2} status=0 QTime=2
[junit4] 2> 667297 DEBUG
(zkCallback-1568-thread-1-processing-n:127.0.0.1:42838_solr)
[n:127.0.0.1:42838_solr ] o.a.s.c.a.OverseerTriggerThread Refreshing
/autoscaling.json with znode version 5
[junit4] 2> 667300 DEBUG
(zkCallback-1568-thread-1-processing-n:127.0.0.1:42838_solr)
[n:127.0.0.1:42838_solr ] o.a.s.c.a.NodeAddedTrigger Initial livenodes:
[127.0.0.1:42838_solr]
[junit4] 2> 667300 DEBUG
(zkCallback-1568-thread-1-processing-n:127.0.0.1:42838_solr)
[n:127.0.0.1:42838_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> 667300 DEBUG
(OverseerAutoScalingTriggerThread-73277068866420739-127.0.0.1:42838_solr-n_0000000000)
[n:127.0.0.1:42838_solr ] o.a.s.c.a.OverseerTriggerThread Processed trigger
updates upto znodeVersion 5
[junit4] 2> 667301 INFO (qtp1528890485-7219) [n:127.0.0.1:42838_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> 667301 DEBUG (qtp1528890485-7220) [n:127.0.0.1:42838_solr ]
o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
[junit4] 2> 667301 INFO (qtp1528890485-7220) [n:127.0.0.1:42838_solr ]
o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/autoscaling
params={wt=javabin&version=2} status=0 QTime=3
[junit4] 2> 667301 DEBUG
(zkCallback-1568-thread-1-processing-n:127.0.0.1:42838_solr)
[n:127.0.0.1:42838_solr ] o.a.s.c.a.OverseerTriggerThread Refreshing
/autoscaling.json with znode version 6
[junit4] 2> 667302 INFO (qtp1528890485-7221) [n:127.0.0.1:42838_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> 667302 DEBUG
(zkCallback-1568-thread-1-processing-n:127.0.0.1:42838_solr)
[n:127.0.0.1:42838_solr ] o.a.s.c.a.NodeAddedTrigger Initial livenodes:
[127.0.0.1:42838_solr]
[junit4] 2> 667302 DEBUG
(zkCallback-1568-thread-1-processing-n:127.0.0.1:42838_solr)
[n:127.0.0.1:42838_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> 667303 DEBUG
(OverseerAutoScalingTriggerThread-73277068866420739-127.0.0.1:42838_solr-n_0000000000)
[n:127.0.0.1:42838_solr ] o.a.s.c.a.OverseerTriggerThread -- clean old
nodeLost markers
[junit4] 2> 667303 DEBUG
(OverseerAutoScalingTriggerThread-73277068866420739-127.0.0.1:42838_solr-n_0000000000)
[n:127.0.0.1:42838_solr ] o.a.s.c.a.OverseerTriggerThread Current
znodeVersion 6, lastZnodeVersion 5
[junit4] 2> 667303 DEBUG
(OverseerAutoScalingTriggerThread-73277068866420739-127.0.0.1:42838_solr-n_0000000000)
[n:127.0.0.1:42838_solr ] o.a.s.c.a.OverseerTriggerThread Processed trigger
updates upto znodeVersion 6
[junit4] 2> 667303 DEBUG (ScheduledTrigger-2607-thread-1)
[n:127.0.0.1:42838_solr ] o.a.s.c.a.NodeAddedTrigger Running
NodeAddedTrigger node_added_trigger
[junit4] 2> 667303 DEBUG (ScheduledTrigger-2607-thread-1)
[n:127.0.0.1:42838_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 1
[junit4] 2> 667304 DEBUG
(OverseerAutoScalingTriggerThread-73277068866420739-127.0.0.1:42838_solr-n_0000000000)
[n:127.0.0.1:42838_solr ] o.a.s.c.a.OverseerTriggerThread -- clean old
nodeLost markers
[junit4] 2> 667304 DEBUG
(OverseerAutoScalingTriggerThread-73277068866420739-127.0.0.1:42838_solr-n_0000000000)
[n:127.0.0.1:42838_solr ] o.a.s.c.a.OverseerTriggerThread Current
znodeVersion 6, lastZnodeVersion 6
[junit4] 2> 667305 INFO
(OverseerThreadFactory-2609-thread-1-processing-n:127.0.0.1:42838_solr)
[n:127.0.0.1:42838_solr ] o.a.s.c.a.c.CreateCollectionCmd Create collection
testNodeAdded
[junit4] 2> 667306 WARN
(OverseerThreadFactory-2609-thread-1-processing-n:127.0.0.1:42838_solr)
[n:127.0.0.1:42838_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> 667307 INFO (qtp1528890485-7224) [n:127.0.0.1:42838_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> 667309 INFO
(OverseerThreadFactory-2609-thread-1-processing-n:127.0.0.1:42838_solr)
[n:127.0.0.1:42838_solr ] o.a.s.c.s.c.a.PolicyHelper returnSession,
curr-time 18607709524 sessionWrapper.createTime 18607709522519966,
this.sessionWrapper.createTime 18607709522519966
[junit4] 2> 667312 DEBUG
(OverseerStateUpdate-73277068866420739-127.0.0.1:42838_solr-n_0000000000)
[n:127.0.0.1:42838_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> 667312 DEBUG
(OverseerStateUpdate-73277068866420739-127.0.0.1:42838_solr-n_0000000000)
[n:127.0.0.1:42838_solr ] o.a.s.c.o.ClusterStateMutator building a new
cName: testNodeAdded
[junit4] 2> 667313 DEBUG
(OverseerStateUpdate-73277068866420739-127.0.0.1:42838_solr-n_0000000000)
[n:127.0.0.1:42838_solr ] o.a.s.c.o.ZkStateWriter going to create_collection
/collections/testNodeAdded/state.json
[junit4] 2> 667415 DEBUG
(OverseerStateUpdate-73277068866420739-127.0.0.1:42838_solr-n_0000000000)
[n:127.0.0.1:42838_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:42838/solr";,
[junit4] 2> "type":"NRT",
[junit4] 2> "waitForFinalState":"false"} current state version: 0
[junit4] 2> 667415 INFO
(OverseerStateUpdate-73277068866420739-127.0.0.1:42838_solr-n_0000000000)
[n:127.0.0.1:42838_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:42838/solr";,
[junit4] 2> "type":"NRT",
[junit4] 2> "waitForFinalState":"false"}
[junit4] 2> 667416 DEBUG
(OverseerStateUpdate-73277068866420739-127.0.0.1:42838_solr-n_0000000000)
[n:127.0.0.1:42838_solr ] o.a.s.c.o.SliceMutator Old Slice: shard1:{
[junit4] 2> "range":"80000000-7fffffff",
[junit4] 2> "state":"active",
[junit4] 2> "replicas":{}}
[junit4] 2> 667416 DEBUG
(OverseerStateUpdate-73277068866420739-127.0.0.1:42838_solr-n_0000000000)
[n:127.0.0.1:42838_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:42838/solr";,
[junit4] 2> "state":"down",
[junit4] 2> "node_name":null,
[junit4] 2> "type":"NRT"}}}
[junit4] 2> 667418 DEBUG
(OverseerStateUpdate-73277068866420739-127.0.0.1:42838_solr-n_0000000000)
[n:127.0.0.1:42838_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:42838/solr";,
[junit4] 2> "type":"NRT",
[junit4] 2> "waitForFinalState":"false"} current state version: 0
[junit4] 2> 667418 INFO
(OverseerStateUpdate-73277068866420739-127.0.0.1:42838_solr-n_0000000000)
[n:127.0.0.1:42838_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:42838/solr";,
[junit4] 2> "type":"NRT",
[junit4] 2> "waitForFinalState":"false"}
[junit4] 2> 667419 DEBUG
(OverseerStateUpdate-73277068866420739-127.0.0.1:42838_solr-n_0000000000)
[n:127.0.0.1:42838_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:42838/solr";,
[junit4] 2> "state":"down",
[junit4] 2> "node_name":null,
[junit4] 2> "type":"NRT"}}}
[junit4] 2> 667419 DEBUG
(OverseerStateUpdate-73277068866420739-127.0.0.1:42838_solr-n_0000000000)
[n:127.0.0.1:42838_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:42838/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:42838/solr";,
[junit4] 2> "state":"down",
[junit4] 2> "node_name":null,
[junit4] 2> "type":"NRT"}}}
[junit4] 2> 667519 DEBUG
(OverseerStateUpdate-73277068866420739-127.0.0.1:42838_solr-n_0000000000)
[n:127.0.0.1:42838_solr ] o.a.s.c.o.ZkStateWriter going to update_collection
/collections/testNodeAdded/state.json version: 0
[junit4] 2> 667620 INFO (qtp1528890485-7224) [n:127.0.0.1:42838_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> 667621 INFO (qtp1528890485-7223) [n:127.0.0.1:42838_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> 667621 INFO (qtp1528890485-7224) [n:127.0.0.1:42838_solr ]
o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647
transient cores
[junit4] 2> 667626 DEBUG
(OverseerStateUpdate-73277068866420739-127.0.0.1:42838_solr-n_0000000000)
[n:127.0.0.1:42838_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:42838/solr";,
[junit4] 2> "node_name":"127.0.0.1:42838_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> 667626 DEBUG
(OverseerStateUpdate-73277068866420739-127.0.0.1:42838_solr-n_0000000000)
[n:127.0.0.1:42838_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:42838/solr";,
[junit4] 2> "node_name":"127.0.0.1:42838_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> 667626 DEBUG
(OverseerStateUpdate-73277068866420739-127.0.0.1:42838_solr-n_0000000000)
[n:127.0.0.1:42838_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:42838/solr","node_name":"127.0.0.1:42838_solr","state":"down","type":"NRT"}
[junit4] 2> 667626 DEBUG
(OverseerStateUpdate-73277068866420739-127.0.0.1:42838_solr-n_0000000000)
[n:127.0.0.1:42838_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:42838/solr";,
[junit4] 2> "node_name":"127.0.0.1:42838_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:42838/solr";,
[junit4] 2> "state":"down",
[junit4] 2> "node_name":null,
[junit4] 2> "type":"NRT"}}}}}
[junit4] 2> 667627 DEBUG
(OverseerStateUpdate-73277068866420739-127.0.0.1:42838_solr-n_0000000000)
[n:127.0.0.1:42838_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:42838/solr";,
[junit4] 2> "node_name":"127.0.0.1:42838_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> 667627 DEBUG
(OverseerStateUpdate-73277068866420739-127.0.0.1:42838_solr-n_0000000000)
[n:127.0.0.1:42838_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:42838/solr";,
[junit4] 2> "node_name":"127.0.0.1:42838_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> 667627 DEBUG
(OverseerStateUpdate-73277068866420739-127.0.0.1:42838_solr-n_0000000000)
[n:127.0.0.1:42838_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:42838/solr","node_name":"127.0.0.1:42838_solr","state":"down","type":"NRT"}
[junit4] 2> 667627 DEBUG
(OverseerStateUpdate-73277068866420739-127.0.0.1:42838_solr-n_0000000000)
[n:127.0.0.1:42838_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:42838/solr";,
[junit4] 2> "node_name":"127.0.0.1:42838_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:42838/solr";,
[junit4] 2> "node_name":"127.0.0.1:42838_solr",
[junit4] 2> "state":"down",
[junit4] 2> "type":"NRT"}}}}}
[junit4] 2> 667727 DEBUG
(OverseerStateUpdate-73277068866420739-127.0.0.1:42838_solr-n_0000000000)
[n:127.0.0.1:42838_solr ] o.a.s.c.o.ZkStateWriter going to update_collection
/collections/testNodeAdded/state.json version: 1
[junit4] 2> 667728 INFO
(zkCallback-1568-thread-1-processing-n:127.0.0.1:42838_solr)
[n:127.0.0.1:42838_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> 667728 INFO
(zkCallback-1568-thread-2-processing-n:127.0.0.1:42838_solr)
[n:127.0.0.1:42838_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> 668306 DEBUG (ScheduledTrigger-2607-thread-2)
[n:127.0.0.1:42838_solr ] o.a.s.c.a.NodeAddedTrigger Running
NodeAddedTrigger node_added_trigger
[junit4] 2> 668307 DEBUG (ScheduledTrigger-2607-thread-2)
[n:127.0.0.1:42838_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 1
[junit4] 2> 668635 INFO (qtp1528890485-7223) [n:127.0.0.1:42838_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> 668636 INFO (qtp1528890485-7224) [n:127.0.0.1:42838_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> 668652 INFO (qtp1528890485-7224) [n:127.0.0.1:42838_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> 668653 INFO (qtp1528890485-7223) [n:127.0.0.1:42838_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> 668654 INFO (qtp1528890485-7224) [n:127.0.0.1:42838_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> 668655 INFO (qtp1528890485-7224) [n:127.0.0.1:42838_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> 668657 INFO (qtp1528890485-7224) [n:127.0.0.1:42838_solr
c:testNodeAdded s:shard1 r:core_node4 x:testNodeAdded_shard1_replica_n2]
o.a.s.m.r.SolrJmxReporter JMX monitoring for
'solr_42838.solr.core.testNodeAdded.shard1.replica_n2' (registry
'solr.core.testNodeAdded.shard1.replica_n2') enabled at server:
com.sun.jmx.mbeanserver.JmxMBeanServer@1ac5a0ba
[junit4] 2> 668657 INFO (qtp1528890485-7224) [n:127.0.0.1:42838_solr
c:testNodeAdded s:shard1 r:core_node4 x:testNodeAdded_shard1_replica_n2]
o.a.s.c.SolrCore solr.RecoveryStrategy.Builder
[junit4] 2> 668657 INFO (qtp1528890485-7224) [n:127.0.0.1:42838_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
[/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/solr/build/solr-core/test/J1/temp/solr.cloud.autoscaling.ComputePlanActionTest_81786C5B037118A0-001/tempDir-001/node1/testNodeAdded_shard1_replica_n2],
dataDir=[/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/solr/build/solr-core/test/J1/temp/solr.cloud.autoscaling.ComputePlanActionTest_81786C5B037118A0-001/tempDir-001/node1/./testNodeAdded_shard1_replica_n2/data/]
[junit4] 2> 668657 INFO (qtp1528890485-7223) [n:127.0.0.1:42838_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> 668657 INFO (qtp1528890485-7223) [n:127.0.0.1:42838_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> 668661 INFO (qtp1528890485-7223) [n:127.0.0.1:42838_solr
c:testNodeAdded s:shard1 r:core_node3 x:testNodeAdded_shard1_replica_n1]
o.a.s.m.r.SolrJmxReporter JMX monitoring for
'solr_42838.solr.core.testNodeAdded.shard1.replica_n1' (registry
'solr.core.testNodeAdded.shard1.replica_n1') enabled at server:
com.sun.jmx.mbeanserver.JmxMBeanServer@1ac5a0ba
[junit4] 2> 668661 INFO (qtp1528890485-7223) [n:127.0.0.1:42838_solr
c:testNodeAdded s:shard1 r:core_node3 x:testNodeAdded_shard1_replica_n1]
o.a.s.c.SolrCore solr.RecoveryStrategy.Builder
[junit4] 2> 668661 INFO (qtp1528890485-7223) [n:127.0.0.1:42838_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
[/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/solr/build/solr-core/test/J1/temp/solr.cloud.autoscaling.ComputePlanActionTest_81786C5B037118A0-001/tempDir-001/node1/testNodeAdded_shard1_replica_n1],
dataDir=[/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/solr/build/solr-core/test/J1/temp/solr.cloud.autoscaling.ComputePlanActionTest_81786C5B037118A0-001/tempDir-001/node1/./testNodeAdded_shard1_replica_n1/data/]
[junit4] 2> 668701 INFO (qtp1528890485-7224) [n:127.0.0.1:42838_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> 668701 INFO (qtp1528890485-7224) [n:127.0.0.1:42838_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> 668701 INFO (qtp1528890485-7223) [n:127.0.0.1:42838_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> 668701 INFO (qtp1528890485-7223) [n:127.0.0.1:42838_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> 668702 INFO (qtp1528890485-7223) [n:127.0.0.1:42838_solr
c:testNodeAdded s:shard1 r:core_node3 x:testNodeAdded_shard1_replica_n1]
o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 668702 INFO (qtp1528890485-7223) [n:127.0.0.1:42838_solr
c:testNodeAdded s:shard1 r:core_node3 x:testNodeAdded_shard1_replica_n1]
o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 668703 INFO (qtp1528890485-7224) [n:127.0.0.1:42838_solr
c:testNodeAdded s:shard1 r:core_node4 x:testNodeAdded_shard1_replica_n2]
o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 668703 INFO (qtp1528890485-7224) [n:127.0.0.1:42838_solr
c:testNodeAdded s:shard1 r:core_node4 x:testNodeAdded_shard1_replica_n2]
o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 668704 INFO (qtp1528890485-7223) [n:127.0.0.1:42838_solr
c:testNodeAdded s:shard1 r:core_node3 x:testNodeAdded_shard1_replica_n1]
o.a.s.s.SolrIndexSearcher Opening
[Searcher@3e1df0f5[testNodeAdded_shard1_replica_n1] main]
[junit4] 2> 668705 INFO (qtp1528890485-7223) [n:127.0.0.1:42838_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> 668705 INFO (qtp1528890485-7224) [n:127.0.0.1:42838_solr
c:testNodeAdded s:shard1 r:core_node4 x:testNodeAdded_shard1_replica_n2]
o.a.s.s.SolrIndexSearcher Opening
[Searcher@5322c24f[testNodeAdded_shard1_replica_n2] main]
[junit4] 2> 668705 INFO (qtp1528890485-7223) [n:127.0.0.1:42838_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> 668706 INFO (qtp1528890485-7223) [n:127.0.0.1:42838_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> 668707 INFO (qtp1528890485-7224) [n:127.0.0.1:42838_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> 668707 INFO (qtp1528890485-7224) [n:127.0.0.1:42838_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> 668707 INFO
(searcherExecutor-2613-thread-1-processing-n:127.0.0.1:42838_solr
x:testNodeAdded_shard1_replica_n1 s:shard1 c:testNodeAdded r:core_node3)
[n:127.0.0.1:42838_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@3e1df0f5[testNodeAdded_shard1_replica_n1]
main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 668707 INFO (qtp1528890485-7223) [n:127.0.0.1:42838_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 1592111451612381184
[junit4] 2> 668707 INFO (qtp1528890485-7224) [n:127.0.0.1:42838_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> 668708 INFO
(searcherExecutor-2612-thread-1-processing-n:127.0.0.1:42838_solr
x:testNodeAdded_shard1_replica_n2 s:shard1 c:testNodeAdded r:core_node4)
[n:127.0.0.1:42838_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@5322c24f[testNodeAdded_shard1_replica_n2]
main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 668708 INFO (qtp1528890485-7224) [n:127.0.0.1:42838_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 1592111451613429760
[junit4] 2> 668715 INFO (qtp1528890485-7224) [n:127.0.0.1:42838_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> 668719 INFO (qtp1528890485-7224) [n:127.0.0.1:42838_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> 668719 INFO (qtp1528890485-7224) [n:127.0.0.1:42838_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> 668719 INFO (qtp1528890485-7224) [n:127.0.0.1:42838_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:42838/solr/testNodeAdded_shard1_replica_n2/
[junit4] 2> 668719 DEBUG
(OverseerStateUpdate-73277068866420739-127.0.0.1:42838_solr-n_0000000000)
[n:127.0.0.1:42838_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> 668720 INFO (qtp1528890485-7224) [n:127.0.0.1:42838_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:42838/solr START
replicas=[http://127.0.0.1:42838/solr/testNodeAdded_shard1_replica_n1/]
nUpdates=100
[junit4] 2> 668722 INFO (qtp1528890485-7226) [n:127.0.0.1:42838_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=1
[junit4] 2> 668820 DEBUG
(OverseerStateUpdate-73277068866420739-127.0.0.1:42838_solr-n_0000000000)
[n:127.0.0.1:42838_solr ] o.a.s.c.o.ZkStateWriter going to update_collection
/collections/testNodeAdded/state.json version: 2
[junit4] 2> 668820 INFO
(zkCallback-1568-thread-3-processing-n:127.0.0.1:42838_solr)
[n:127.0.0.1:42838_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> 668820 INFO
(zkCallback-1568-thread-2-processing-n:127.0.0.1:42838_solr)
[n:127.0.0.1:42838_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> 669020 INFO (qtp1528890485-7224) [n:127.0.0.1:42838_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:42838/solr DONE. We have no versions. sync failed.
[junit4] 2> 669020 INFO (qtp1528890485-7224) [n:127.0.0.1:42838_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> 669020 INFO (qtp1528890485-7224) [n:127.0.0.1:42838_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> 669020 INFO (qtp1528890485-7224) [n:127.0.0.1:42838_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> 669023 INFO (qtp1528890485-7224) [n:127.0.0.1:42838_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:42838/solr/testNodeAdded_shard1_replica_n2/ shard1
[junit4] 2> 669024 DEBUG
(OverseerStateUpdate-73277068866420739-127.0.0.1:42838_solr-n_0000000000)
[n:127.0.0.1:42838_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:42838/solr";,
[junit4] 2> "core":"testNodeAdded_shard1_replica_n2",
[junit4] 2> "state":"active"} current state version: 0
[junit4] 2> 669124 DEBUG
(OverseerStateUpdate-73277068866420739-127.0.0.1:42838_solr-n_0000000000)
[n:127.0.0.1:42838_solr ] o.a.s.c.o.ZkStateWriter going to update_collection
/collections/testNodeAdded/state.json version: 3
[junit4] 2> 669125 INFO
(zkCallback-1568-thread-3-processing-n:127.0.0.1:42838_solr)
[n:127.0.0.1:42838_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> 669125 INFO
(zkCallback-1568-thread-2-processing-n:127.0.0.1:42838_solr)
[n:127.0.0.1:42838_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> 669174 INFO (qtp1528890485-7224) [n:127.0.0.1:42838_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> 669175 DEBUG
(OverseerStateUpdate-73277068866420739-127.0.0.1:42838_solr-n_0000000000)
[n:127.0.0.1:42838_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:42838/solr";,
[junit4] 2> "node_name":"127.0.0.1:42838_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> 669175 DEBUG
(OverseerStateUpdate-73277068866420739-127.0.0.1:42838_solr-n_0000000000)
[n:127.0.0.1:42838_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:42838/solr";,
[junit4] 2> "node_name":"127.0.0.1:42838_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> 669175 DEBUG
(OverseerStateUpdate-73277068866420739-127.0.0.1:42838_solr-n_0000000000)
[n:127.0.0.1:42838_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:42838/solr","node_name":"127.0.0.1:42838_solr","state":"active","type":"NRT","leader":"true"}
[junit4] 2> 669175 DEBUG
(OverseerStateUpdate-73277068866420739-127.0.0.1:42838_solr-n_0000000000)
[n:127.0.0.1:42838_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:42838/solr";,
[junit4] 2> "node_name":"127.0.0.1:42838_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:42838/solr";,
[junit4] 2> "node_name":"127.0.0.1:42838_solr",
[junit4] 2> "state":"active",
[junit4] 2> "type":"NRT",
[junit4] 2> "leader":"true"}}}}}
[junit4] 2> 669176 INFO (qtp1528890485-7224) [n:127.0.0.1:42838_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=1555
[junit4] 2> 669276 DEBUG
(OverseerStateUpdate-73277068866420739-127.0.0.1:42838_solr-n_0000000000)
[n:127.0.0.1:42838_solr ] o.a.s.c.o.ZkStateWriter going to update_collection
/collections/testNodeAdded/state.json version: 4
[junit4] 2> 669276 INFO
(zkCallback-1568-thread-1-processing-n:127.0.0.1:42838_solr)
[n:127.0.0.1:42838_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> 669276 INFO
(zkCallback-1568-thread-2-processing-n:127.0.0.1:42838_solr)
[n:127.0.0.1:42838_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> 669307 DEBUG (ScheduledTrigger-2607-thread-2)
[n:127.0.0.1:42838_solr ] o.a.s.c.a.NodeAddedTrigger Running
NodeAddedTrigger node_added_trigger
[junit4] 2> 669307 DEBUG (ScheduledTrigger-2607-thread-2)
[n:127.0.0.1:42838_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 1
[junit4] 2> 669720 INFO (qtp1528890485-7223) [n:127.0.0.1:42838_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=2099
[junit4] 2> 669721 DEBUG
(OverseerStateUpdate-73277068866420739-127.0.0.1:42838_solr-n_0000000000)
[n:127.0.0.1:42838_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:42838/solr";,
[junit4] 2> "node_name":"127.0.0.1:42838_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> 669721 DEBUG
(OverseerStateUpdate-73277068866420739-127.0.0.1:42838_solr-n_0000000000)
[n:127.0.0.1:42838_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:42838/solr";,
[junit4] 2> "node_name":"127.0.0.1:42838_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> 669721 DEBUG
(OverseerStateUpdate-73277068866420739-127.0.0.1:42838_solr-n_0000000000)
[n:127.0.0.1:42838_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:42838/solr","node_name":"127.0.0.1:42838_solr","state":"active","type":"NRT"}
[junit4] 2> 669721 DEBUG
(OverseerStateUpdate-73277068866420739-127.0.0.1:42838_solr-n_0000000000)
[n:127.0.0.1:42838_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:42838/solr";,
[junit4] 2> "node_name":"127.0.0.1:42838_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:42838/solr";,
[junit4] 2> "node_name":"127.0.0.1:42838_solr",
[junit4] 2> "state":"active",
[junit4] 2> "type":"NRT",
[junit4] 2> "leader":"true"}}}}}
[junit4] 2> 669725 INFO (qtp1528890485-7221) [n:127.0.0.1:42838_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> 669822 DEBUG
(OverseerStateUpdate-73277068866420739-127.0.0.1:42838_solr-n_0000000000)
[n:127.0.0.1:42838_solr ] o.a.s.c.o.ZkStateWriter going to update_collection
/collections/testNodeAdded/state.json version: 5
[junit4] 2> 669822 INFO
(zkCallback-1568-thread-2-processing-n:127.0.0.1:42838_solr)
[n:127.0.0.1:42838_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> 669822 INFO
(zkCallback-1568-thread-1-processing-n:127.0.0.1:42838_solr)
[n:127.0.0.1:42838_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> 670307 DEBUG (ScheduledTrigger-2607-thread-2)
[n:127.0.0.1:42838_solr ] o.a.s.c.a.NodeAddedTrigger Running
NodeAddedTrigger node_added_trigger
[junit4] 2> 670307 DEBUG (ScheduledTrigger-2607-thread-2)
[n:127.0.0.1:42838_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 1
[junit4] 2> 670725 INFO (qtp1528890485-7221) [n:127.0.0.1:42838_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=3423
[junit4] 2> 670732 INFO (qtp1528890485-7219) [n:127.0.0.1:42838_solr ]
o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics
params={wt=javabin&version=2&key=solr.core.testNodeAdded.shard1.replica_n1:INDEX.sizeInBytes&key=solr.core.testNodeAdded.shard1.replica_n2:INDEX.sizeInBytes}
status=0 QTime=1
[junit4] 2> 670735 INFO (qtp1528890485-7224) [n:127.0.0.1:42838_solr ]
o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics
params={prefix=CONTAINER.fs.usableSpace,CORE.coreName&wt=javabin&version=2&group=solr.node,solr.core}
status=0 QTime=1
[junit4] 2> 670736 DEBUG (qtp1528890485-7220) [n:127.0.0.1:42838_solr ]
o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
[junit4] 2> 670737 INFO (qtp1528890485-7220) [n:127.0.0.1:42838_solr ]
o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/autoscaling
params={wt=javabin&version=2} status=0 QTime=9
[junit4] 2> 670738 INFO
(TEST-ComputePlanActionTest.testNodeAdded-seed#[81786C5B037118A0]) [ ]
o.e.j.s.Server jetty-9.4.8.v20171121, build timestamp:
2017-11-21T16:27:37-05:00, git hash: 82b8fb23f757335bb3329d540ce37a2a2615f0a8
[junit4] 2> 670740 DEBUG
(zkCallback-1568-thread-2-processing-n:127.0.0.1:42838_solr)
[n:127.0.0.1:42838_solr ] o.a.s.c.a.OverseerTriggerThread Refreshing
/autoscaling.json with znode version 7
[junit4] 2> 670740 DEBUG
(zkCallback-1568-thread-2-processing-n:127.0.0.1:42838_solr)
[n:127.0.0.1:42838_solr ] o.a.s.c.a.NodeAddedTrigger Initial livenodes:
[127.0.0.1:42838_solr]
[junit4] 2> 670740 DEBUG
(zkCallback-1568-thread-2-processing-n:127.0.0.1:42838_solr)
[n:127.0.0.1:42838_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> 670740 DEBUG
(OverseerAutoScalingTriggerThread-73277068866420739-127.0.0.1:42838_solr-n_0000000000)
[n:127.0.0.1:42838_solr ] o.a.s.c.a.OverseerTriggerThread Processed trigger
updates upto znodeVersion 7
[junit4] 2> 670743 DEBUG
(OverseerAutoScalingTriggerThread-73277068866420739-127.0.0.1:42838_solr-n_0000000000)
[n:127.0.0.1:42838_solr ] o.a.s.c.a.OverseerTriggerThread -- clean old
nodeLost markers
[junit4] 2> 670743 DEBUG
(OverseerAutoScalingTriggerThread-73277068866420739-127.0.0.1:42838_solr-n_0000000000)
[n:127.0.0.1:42838_solr ] o.a.s.c.a.OverseerTriggerThread Current
znodeVersion 7, lastZnodeVersion 7
[junit4] 2> 670745 INFO
(TEST-ComputePlanActionTest.testNodeAdded-seed#[81786C5B037118A0]) [ ]
o.e.j.s.session DefaultSessionIdManager workerName=node0
[junit4] 2> 670745 INFO
(TEST-ComputePlanActionTest.testNodeAdded-seed#[81786C5B037118A0]) [ ]
o.e.j.s.session No SessionScavenger set, using defaults
[junit4] 2> 670745 INFO
(TEST-ComputePlanActionTest.testNodeAdded-seed#[81786C5B037118A0]) [ ]
o.e.j.s.session Scavenging every 600000ms
[junit4] 2> 670746 INFO
(TEST-ComputePlanActionTest.testNodeAdded-seed#[81786C5B037118A0]) [ ]
o.e.j.s.h.ContextHandler Started
o.e.j.s.ServletContextHandler@7bf23c5c{/solr,null,AVAILABLE}
[junit4] 2> 670746 INFO
(TEST-ComputePlanActionTest.testNodeAdded-seed#[81786C5B037118A0]) [ ]
o.e.j.s.AbstractConnector Started
ServerConnector@628572b1{HTTP/1.1,[http/1.1]}{127.0.0.1:40932}
[junit4] 2> 670746 INFO
(TEST-ComputePlanActionTest.testNodeAdded-seed#[81786C5B037118A0]) [ ]
o.e.j.s.Server Started @672502ms
[junit4] 2> 670746 INFO
(TEST-ComputePlanActionTest.testNodeAdded-seed#[81786C5B037118A0]) [ ]
o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr,
hostPort=40932}
[junit4] 2> 670746 ERROR
(TEST-ComputePlanActionTest.testNodeAdded-seed#[81786C5B037118A0]) [ ]
o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be
missing or incomplete.
[junit4] 2> 670747 INFO
(TEST-ComputePlanActionTest.testNodeAdded-seed#[81786C5B037118A0]) [ ]
o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version
8.0.0
[junit4] 2> 670747 INFO
(TEST-ComputePlanActionTest.testNodeAdded-seed#[81786C5B037118A0]) [ ]
o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 670747 INFO
(TEST-ComputePlanActionTest.testNodeAdded-seed#[81786C5B037118A0]) [ ]
o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 670747 INFO
(TEST-ComputePlanActionTest.testNodeAdded-seed#[81786C5B037118A0]) [ ]
o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time:
2018-02-11T13:30:02.299Z
[junit4] 2> 670749 INFO (zkConnectionManagerCallback-1580-thread-1) [
] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 670750 INFO
(TEST-ComputePlanActionTest.testNodeAdded-seed#[81786C5B037118A0]) [ ]
o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 670759 INFO
(TEST-ComputePlanActionTest.testNodeAdded-seed#[81786C5B037118A0]) [ ]
o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:37378/solr
[junit4] 2> 670761 INFO (zkConnectionManagerCallback-1584-thread-1) [
] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 670764 INFO
(zkConnectionManagerCallback-1586-thread-1-processing-n:127.0.0.1:40932_solr)
[n:127.0.0.1:40932_solr ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 670770 INFO
(TEST-ComputePlanActionTest.testNodeAdded-seed#[81786C5B037118A0])
[n:127.0.0.1:40932_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (0) -> (1)
[junit4] 2> 670773 INFO
(TEST-ComputePlanActionTest.testNodeAdded-seed#[81786C5B037118A0])
[n:127.0.0.1:40932_solr ] o.a.s.c.Overseer Overseer (id=null) closing
[junit4] 2> 670775 INFO
(TEST-ComputePlanActionTest.testNodeAdded-seed#[81786C5B037118A0])
[n:127.0.0.1:40932_solr ] o.a.s.c.ZkController Register node as live in
ZooKeeper:/live_nodes/127.0.0.1:40932_solr
[junit4] 2> 670776 DEBUG
(OverseerStateUpdate-73277068866420739-127.0.0.1:42838_solr-n_0000000000)
[n:127.0.0.1:42838_solr ] o.a.s.c.Overseer processMessage: queueSize: 1,
message = {
[junit4] 2> "operation":"downnode",
[junit4] 2> "node_name":"127.0.0.1:40932_solr"} current state version: 0
[junit4] 2> 670776 DEBUG
(OverseerStateUpdate-73277068866420739-127.0.0.1:42838_solr-n_0000000000)
[n:127.0.0.1:42838_solr ] o.a.s.c.o.NodeMutator DownNode state invoked for
node: 127.0.0.1:40932_solr
[junit4] 2> 670779 INFO (zkCallback-1576-thread-2) [ ]
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
[junit4] 2> 670780 INFO
(zkCallback-1568-thread-2-processing-n:127.0.0.1:42838_solr)
[n:127.0.0.1:42838_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (1) -> (2)
[junit4] 2> 670780 INFO (zkCallback-1576-thread-1) [ ]
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
[junit4] 2> 670785 INFO
(zkCallback-1585-thread-1-processing-n:127.0.0.1:40932_solr)
[n:127.0.0.1:40932_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (1) -> (2)
[junit4] 2> 670836 INFO
(TEST-ComputePlanActionTest.testNodeAdded-seed#[81786C5B037118A0])
[n:127.0.0.1:40932_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for
'solr_40932.solr.node' (registry 'solr.node') enabled at server:
com.sun.jmx.mbeanserver.JmxMBeanServer@1ac5a0ba
[junit4] 2> 670845 INFO
(TEST-ComputePlanActionTest.testNodeAdded-seed#[81786C5B037118A0])
[n:127.0.0.1:40932_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for
'solr_40932.solr.jvm' (registry 'solr.jvm') enabled at server:
com.sun.jmx.mbeanserver.JmxMBeanServer@1ac5a0ba
[junit4] 2> 670845 INFO
(TEST-ComputePlanActionTest.testNodeAdded-seed#[81786C5B037118A0])
[n:127.0.0.1:40932_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for
'solr_40932.solr.jetty' (registry 'solr.jetty') enabled at server:
com.sun.jmx.mbeanserver.JmxMBeanServer@1ac5a0ba
[junit4] 2> 670846 INFO
(TEST-ComputePlanActionTest.testNodeAdded-seed#[81786C5B037118A0])
[n:127.0.0.1:40932_solr ] o.a.s.c.CorePropertiesLocator Found 0 core
definitions underneath
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/solr/build/solr-core/test/J1/temp/solr.cloud.autoscaling.ComputePlanActionTest_81786C5B037118A0-001/tempDir-001/node2/.
[junit4] 2> 671307 DEBUG (ScheduledTrigger-2607-thread-2)
[n:127.0.0.1:42838_solr ] o.a.s.c.a.NodeAddedTrigger Running
NodeAddedTrigger node_added_trigger
[junit4] 2> 671307 DEBUG (ScheduledTrigger-2607-thread-2)
[n:127.0.0.1:42838_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 2
[junit4] 2> 671307 DEBUG (ScheduledTrigger-2607-thread-2)
[n:127.0.0.1:42838_solr ] o.a.s.c.a.NodeAddedTrigger Tracking new node:
127.0.0.1:40932_solr at time 18607713522923597
[junit4] 2> 671308 INFO
(OverseerCollectionConfigSetProcessor-73277068866420739-127.0.0.1:42838_solr-n_0000000000)
[n:127.0.0.1:42838_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> 672308 DEBUG (ScheduledTrigger-2607-thread-2)
[n:127.0.0.1:42838_solr ] o.a.s.c.a.NodeAddedTrigger Running
NodeAddedTrigger node_added_trigger
[junit4] 2> 672309 DEBUG (ScheduledTrigger-2607-thread-2)
[n:127.0.0.1:42838_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 2
[junit4] 2> 672309 DEBUG (ScheduledTrigger-2607-thread-2)
[n:127.0.0.1:42838_solr ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger
node_added_trigger firing registered processor for nodes:
[127.0.0.1:40932_solr] added at times [18607713522923597], now=18607714524193627
[junit4] 2> 672309 DEBUG (ScheduledTrigger-2607-thread-2)
[n:127.0.0.1:42838_solr ] o.a.s.c.a.ScheduledTriggers ++++++++ Cooldown
inactive - processing event: {
[junit4] 2> "id":"421b9dea9db84dT4ybehnjv8aqtxk3mlj1wf80d8",
[junit4] 2> "source":"node_added_trigger",
[junit4] 2> "eventTime":18607713522923597,
[junit4] 2> "eventType":"NODEADDED",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[18607713522923597],
[junit4] 2> "nodeNames":["127.0.0.1:40932_solr"]}}
[junit4] 2> 672310 DEBUG (ScheduledTrigger-2607-thread-2)
[n:127.0.0.1:42838_solr ] o.a.s.c.a.ScheduledTriggers Pausing all triggers:
[node_added_trigger]
[junit4] 2> 672312 INFO (ScheduledTrigger-2607-thread-2)
[n:127.0.0.1:42838_solr ] o.a.s.c.a.SystemLogListener Collection .system
does not exist, disabling logging.
[junit4] 2> 672313 DEBUG
(AutoscalingActionExecutor-2608-thread-1-processing-n:127.0.0.1:42838_solr)
[n:127.0.0.1:42838_solr ] o.a.s.c.a.ScheduledTriggers -- processing actions
for {
[junit4] 2> "id":"421b9dea9db84dT4ybehnjv8aqtxk3mlj1wf80d8",
[junit4] 2> "source":"node_added_trigger",
[junit4] 2> "eventTime":18607713522923597,
[junit4] 2> "eventType":"NODEADDED",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[18607713522923597],
[junit4] 2> "_enqueue_time_":18607714525562023,
[junit4] 2> "nodeNames":["127.0.0.1:40932_solr"]}}
[junit4] 2> 672313 DEBUG
(AutoscalingActionExecutor-2608-thread-1-processing-n:127.0.0.1:42838_solr)
[n:127.0.0.1:42838_solr ] o.a.s.c.a.ComputePlanAction -- processing event: {
[junit4] 2> "id":"421b9dea9db84dT4ybehnjv8aqtxk3mlj1wf80d8",
[junit4] 2> "source":"node_added_trigger",
[junit4] 2> "eventTime":18607713522923597,
[junit4] 2> "eventType":"NODEADDED",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[18607713522923597],
[junit4] 2> "_enqueue_time_":18607714525562023,
[junit4] 2> "nodeNames":["127.0.0.1:40932_solr"]}} with context
properties: {BEFORE_ACTION=[compute_plan]}
[junit4] 2> 672322 INFO (qtp1311237093-7276) [n:127.0.0.1:40932_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> 672322 INFO (qtp1528890485-7219) [n:127.0.0.1:42838_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> 672324 INFO (qtp1528890485-7220) [n:127.0.0.1:42838_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> 672324 INFO
(AutoscalingActionExecutor-2608-thread-1-processing-n:127.0.0.1:42838_solr)
[n:127.0.0.1:42838_solr ] o.a.s.c.a.ComputePlanAction Computed Plan:
action=MOVEREPLICA&collection=testNodeAdded&targetNode=127.0.0.1:40932_solr&inPlaceMove=true&replica=core_node3
[junit4] 2> 672325 INFO
(AutoscalingActionExecutor-2608-thread-1-processing-n:127.0.0.1:42838_solr)
[n:127.0.0.1:42838_solr ] o.a.s.c.s.c.a.PolicyHelper returnSession,
curr-time 18607714540 sessionWrapper.createTime 18607714539459793,
this.sessionWrapper.createTime 18607714539459793
[junit4] 2> 672325 DEBUG
(TEST-ComputePlanActionTest.testNodeAdded-seed#[81786C5B037118A0]) [ ]
o.a.s.c.a.ComputePlanActionTest -------------_ FINAL STATE --------------
[junit4] 2> 672326 DEBUG
(AutoscalingActionExecutor-2608-thread-1-processing-n:127.0.0.1:42838_solr)
[n:127.0.0.1:42838_solr ] o.a.s.c.a.ScheduledTriggers Resuming trigger:
node_added_trigger after 5000ms
[junit4] 2> 672326 DEBUG
(AutoscalingActionExecutor-2608-thread-1-processing-n:127.0.0.1:42838_solr)
[n:127.0.0.1:42838_solr ] o.a.s.c.a.ScheduledTriggers -- processing took 12
ms for event id=421b9dea9db84dT4ybehnjv8aqtxk3mlj1wf80d8
[junit4] 2> 672326 INFO (qtp1311237093-7277) [n:127.0.0.1:40932_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> 672326 DEBUG
(TEST-ComputePlanActionTest.testNodeAdded-seed#[81786C5B037118A0]) [ ]
o.a.s.c.a.ComputePlanActionTest * Node values: 127.0.0.1:40932_solr
[junit4] 2> {
[junit4] 2> "node":"127.0.0.1:40932_solr",
[junit4] 2> "cores":0,
[junit4] 2> "port":"40932",
[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":51.07687759399414}
[junit4] 2> 672327 INFO (qtp1528890485-7219) [n:127.0.0.1:42838_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> 672328 DEBUG
(TEST-ComputePlanActionTest.testNodeAdded-seed#[81786C5B037118A0]) [ ]
o.a.s.c.a.ComputePlanActionTest * Node values: 127.0.0.1:42838_solr
[junit4] 2> {
[junit4] 2> "node":"127.0.0.1:42838_solr",
[junit4] 2> "cores":2,
[junit4] 2> "port":"42838",
[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":51.07687759399414}
[junit4] 2> 672328 DEBUG
(TEST-ComputePlanActionTest.testNodeAdded-seed#[81786C5B037118A0]) [ ]
o.a.s.c.a.ComputePlanActionTest * Live nodes: [127.0.0.1:40932_solr,
127.0.0.1:42838_solr]
[junit4] 2> 672328 DEBUG
(TEST-ComputePlanActionTest.testNodeAdded-seed#[81786C5B037118A0]) [ ]
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:42838/solr";,
[junit4] 2> "node_name":"127.0.0.1:42838_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:42838/solr";,
[junit4] 2> "node_name":"127.0.0.1:42838_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>
[...truncated too long message...]
2.2} hits=1 status=0 QTime=0
[junit4] 2> 47031 T46 C14 oasc.SolrCore.execute [collection1] webapp=null
path=null params={q=id:2&qt=&start=0&rows=20&version=2.2} hits=1 status=0
QTime=0
[junit4] 2> 47031 T46 oas.SolrTestCaseJ4.deleteCore ###deleteCore
[junit4] 2> 47032 T46 oasc.CoreContainer.shutdown Shutting down
CoreContainer instance=924785837
[junit4] 2> 47032 T46 oasm.SolrMetricManager.closeReporters Closing metric
reporters for registry=solr.node, tag=null
[junit4] 2> 47032 T46 oasmr.SolrJmxReporter.close Closing reporter
[org.apache.solr.metrics.reporters.SolrJmxReporter@768af3e8: rootName = null,
domain = solr.node, service url = null, agent id = null] for registry solr.node
/ null
[junit4] 2> 47032 T46 oasm.SolrMetricManager.closeReporters Closing metric
reporters for registry=solr.jvm, tag=null
[junit4] 2> 47032 T46 oasmr.SolrJmxReporter.close Closing reporter
[org.apache.solr.metrics.reporters.SolrJmxReporter@4f7a20d2: rootName = null,
domain = solr.jvm, service url = null, agent id = null] for registry solr.jvm /
null
[junit4] 2> 47032 T46 oasm.SolrMetricManager.closeReporters Closing metric
reporters for registry=solr.jetty, tag=null
[junit4] 2> 47033 T46 oasmr.SolrJmxReporter.close Closing reporter
[org.apache.solr.metrics.reporters.SolrJmxReporter@291edf08: rootName = null,
domain = solr.jetty, service url = null, agent id = null] for registry
solr.jetty / null
[junit4] 2> 47034 T250 x:x:collection1 oasc.SolrCore.close [collection1]
CLOSING SolrCore org.apache.solr.core.SolrCore@5ce53627
[junit4] 2> 47034 T250 x:x:collection1
oasm.SolrMetricManager.closeReporters Closing metric reporters for
registry=solr.core.collection1, tag=1558525479
[junit4] 2> 47034 T250 x:x:collection1 oasmr.SolrJmxReporter.close Closing
reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@11d487c9: rootName
= null, domain = solr.core.collection1, service url = null, agent id = null]
for registry solr.core.collection1 / null
[junit4] 2> 47040 T46 oejs.AbstractConnector.doStop Stopped
ServerConnector@c7b9c95{SSL,[ssl, http/1.1]}{127.0.0.1:0}
[junit4] 2> 47041 T46 oasc.CoreContainer.shutdown Shutting down
CoreContainer instance=1659423280
[junit4] 2> 47041 T46 oasm.SolrMetricManager.closeReporters Closing metric
reporters for registry=solr.node, tag=null
[junit4] 2> 47041 T46 oasm.SolrMetricManager.closeReporters Closing metric
reporters for registry=solr.jvm, tag=null
[junit4] 2> 47041 T46 oasm.SolrMetricManager.closeReporters Closing metric
reporters for registry=solr.jetty, tag=null
[junit4] 2> 47042 T253 x:x:collection1 oasc.SolrCore.close [collection1]
CLOSING SolrCore org.apache.solr.core.SolrCore@1dd5cd0b
[junit4] 2> 47042 T253 x:x:collection1
oasm.SolrMetricManager.closeReporters Closing metric reporters for
registry=solr.core.collection1, tag=500550923
[junit4] 2> 47052 T46 oejsh.ContextHandler.doStop Stopped
o.e.j.s.ServletContextHandler@73a87fa6{/solr,null,UNAVAILABLE}
[junit4] 2> 47052 T46 oejss.HouseKeeper.stopScavenging Stopped scavenging
[junit4] 2> 47055 T46 oas.SolrTestCaseJ4.tearDown ###Ending
testFullImportInnerEntity
[junit4] 2> 47055 T46 oas.SolrTestCaseJ4.clearObjectTrackerAndCheckEmpty
------------------------------------------------------- Done waiting for
tracked resources to be released
[junit4] 2> Feb 11, 2018 2:15:21 PM
com.carrotsearch.randomizedtesting.ThreadLeakControl checkThreadLeaks
[junit4] 2> WARNING: Will linger awaiting termination of 1 leaked
thread(s).
[junit4] 2> Feb 11, 2018 2:15:41 PM
com.carrotsearch.randomizedtesting.ThreadLeakControl checkThreadLeaks
[junit4] 2> SEVERE: 1 thread leaked from SUITE scope at
org.apache.solr.handler.dataimport.TestSolrEntityProcessorEndToEnd:
[junit4] 2> 1) Thread[id=120, name=qtp1706926551-120,
state=TIMED_WAITING, group=TGRP-TestSolrEntityProcessorEndToEnd]
[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 11, 2018 2:15:41 PM
com.carrotsearch.randomizedtesting.ThreadLeakControl tryToInterruptAll
[junit4] 2> INFO: Starting to interrupt leaked threads:
[junit4] 2> 1) Thread[id=120, name=qtp1706926551-120,
state=TIMED_WAITING, group=TGRP-TestSolrEntityProcessorEndToEnd]
[junit4] 2> Feb 11, 2018 2:15:44 PM
com.carrotsearch.randomizedtesting.ThreadLeakControl tryToInterruptAll
[junit4] 2> SEVERE: There are still zombie threads that couldn't be
terminated:
[junit4] 2> 1) Thread[id=120, name=qtp1706926551-120,
state=TIMED_WAITING, group=TGRP-TestSolrEntityProcessorEndToEnd]
[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):
{dbdesc_s=Lucene50(blocksize=128), dbid_s=PostingsFormat(name=MockRandom),
id=PostingsFormat(name=MockRandom), desc=Lucene50(blocksize=128)},
docValues:{}, maxPointsInLeafNode=1449, maxMBSortInHeap=6.881502100490428,
sim=Asserting(org.apache.lucene.search.similarities.AssertingSimilarity@2296cb72),
locale=ar-LY, timezone=Pacific/Fiji
[junit4] 2> NOTE: Linux 3.13.0-88-generic amd64/Oracle Corporation
1.8.0_144 (64-bit)/cpus=4,threads=3,free=120060944,total=292028416
[junit4] 2> NOTE: All tests run in this JVM: [TestDateFormatTransformer,
TestEphemeralCache, TestDocBuilder, TestDataConfig, TestVariableResolver,
TestJdbcDataSource, TestFieldReader, TestURLDataSource, TestRegexTransformer,
TestSolrEntityProcessorEndToEnd]
[junit4] 2> NOTE: reproduce with: ant test
-Dtestcase=TestSolrEntityProcessorEndToEnd -Dtests.seed=A746474AAE52596C
-Dtests.multiplier=2 -Dtests.slow=true -Dtests.locale=ar-LY
-Dtests.timezone=Pacific/Fiji -Dtests.asserts=true
-Dtests.file.encoding=ISO-8859-1
[junit4] ERROR 0.00s J2 | TestSolrEntityProcessorEndToEnd (suite) <<<
[junit4] > Throwable #1:
com.carrotsearch.randomizedtesting.ThreadLeakError: 1 thread leaked from SUITE
scope at org.apache.solr.handler.dataimport.TestSolrEntityProcessorEndToEnd:
[junit4] > 1) Thread[id=120, name=qtp1706926551-120,
state=TIMED_WAITING, group=TGRP-TestSolrEntityProcessorEndToEnd]
[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([A746474AAE52596C]:0)Throwable #2:
com.carrotsearch.randomizedtesting.ThreadLeakError: There are still zombie
threads that couldn't be terminated:
[junit4] > 1) Thread[id=120, name=qtp1706926551-120,
state=TIMED_WAITING, group=TGRP-TestSolrEntityProcessorEndToEnd]
[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([A746474AAE52596C]:0)
[junit4] Completed [38/38 (1!)] on J2 in 61.27s, 7 tests, 2 errors <<<
FAILURES!
[...truncated 42599 lines...]
---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscr...@lucene.apache.org
For additional commands, e-mail: dev-h...@lucene.apache.org
