Build: https://jenkins.thetaphi.de/job/Lucene-Solr-master-Windows/6946/
Java: 32bit/jdk1.8.0_144 -client -XX:+UseG1GC
1 tests failed.
FAILED: org.apache.solr.cloud.autoscaling.ComputePlanActionTest.testNodeLost
Error Message:
The operations computed by ComputePlanAction should not be null
Stack Trace:
java.lang.AssertionError: The operations computed by ComputePlanAction should
not be null
at
__randomizedtesting.SeedInfo.seed([B1DFD0131B7C99E4:ECA1EED9896FC62]: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.testNodeLost(ComputePlanActionTest.java:193)
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 11655 lines...]
[junit4] Suite: org.apache.solr.cloud.autoscaling.ComputePlanActionTest
[junit4] 2> Creating dataDir:
C:\Users\jenkins\workspace\Lucene-Solr-master-Windows\solr\build\solr-core\test\J1\temp\solr.cloud.autoscaling.ComputePlanActionTest_B1DFD0131B7C99E4-001\init-core-data-001
[junit4] 2> 215775 WARN
(SUITE-ComputePlanActionTest-seed#[B1DFD0131B7C99E4]-worker) [ ]
o.a.s.SolrTestCaseJ4 startTrackingSearchers: numOpens=1 numCloses=1
[junit4] 2> 215776 INFO
(SUITE-ComputePlanActionTest-seed#[B1DFD0131B7C99E4]-worker) [ ]
o.a.s.SolrTestCaseJ4 Using PointFields (NUMERIC_POINTS_SYSPROP=true)
w/NUMERIC_DOCVALUES_SYSPROP=false
[junit4] 2> 215779 INFO
(SUITE-ComputePlanActionTest-seed#[B1DFD0131B7C99E4]-worker) [ ]
o.a.s.SolrTestCaseJ4 Randomized ssl (true) and clientAuth (false) via:
@org.apache.solr.util.RandomizeSSL(reason=, value=NaN, ssl=NaN, clientAuth=NaN)
[junit4] 2> 215874 INFO
(SUITE-ComputePlanActionTest-seed#[B1DFD0131B7C99E4]-worker) [ ]
o.a.s.SolrTestCaseJ4 SecureRandom sanity checks:
test.solr.allowed.securerandom=null & java.security.egd=file:/dev/./urandom
[junit4] 2> 215877 INFO
(SUITE-ComputePlanActionTest-seed#[B1DFD0131B7C99E4]-worker) [ ]
o.a.s.c.MiniSolrCloudCluster Starting cluster of 1 servers in
C:\Users\jenkins\workspace\Lucene-Solr-master-Windows\solr\build\solr-core\test\J1\temp\solr.cloud.autoscaling.ComputePlanActionTest_B1DFD0131B7C99E4-001\tempDir-001
[junit4] 2> 215877 INFO
(SUITE-ComputePlanActionTest-seed#[B1DFD0131B7C99E4]-worker) [ ]
o.a.s.c.ZkTestServer STARTING ZK TEST SERVER
[junit4] 2> 215877 INFO (Thread-59) [ ] o.a.s.c.ZkTestServer client
port:0.0.0.0/0.0.0.0:0
[junit4] 2> 215877 INFO (Thread-59) [ ] o.a.s.c.ZkTestServer Starting
server
[junit4] 2> 215882 ERROR (Thread-59) [ ] 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> 215978 INFO
(SUITE-ComputePlanActionTest-seed#[B1DFD0131B7C99E4]-worker) [ ]
o.a.s.c.ZkTestServer start zk server on port:61539
[junit4] 2> 216002 WARN (NIOServerCxn.Factory:0.0.0.0/0.0.0.0:0) [ ]
o.a.z.s.NIOServerCnxn caught end of stream exception
[junit4] 2> EndOfStreamException: Unable to read additional data from
client sessionid 0x15efae3b8950000, likely client has closed socket
[junit4] 2> at
org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:239)
[junit4] 2> at
org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:203)
[junit4] 2> at java.lang.Thread.run(Thread.java:748)
[junit4] 2> 216033 INFO (jetty-launcher-59-thread-1) [ ]
o.e.j.s.Server jetty-9.3.20.v20170531
[junit4] 2> 216034 INFO (jetty-launcher-59-thread-1) [ ]
o.e.j.s.h.ContextHandler Started
o.e.j.s.ServletContextHandler@32ec2b{/solr,null,AVAILABLE}
[junit4] 2> 216053 INFO (jetty-launcher-59-thread-1) [ ]
o.e.j.s.AbstractConnector Started ServerConnector@1c8eca2{SSL,[ssl,
http/1.1]}{127.0.0.1:61543}
[junit4] 2> 216053 INFO (jetty-launcher-59-thread-1) [ ]
o.e.j.s.Server Started @223404ms
[junit4] 2> 216053 INFO (jetty-launcher-59-thread-1) [ ]
o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr,
hostPort=61543}
[junit4] 2> 216054 ERROR (jetty-launcher-59-thread-1) [ ]
o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be
missing or incomplete.
[junit4] 2> 216054 INFO (jetty-launcher-59-thread-1) [ ]
o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr™ version
8.0.0
[junit4] 2> 216054 INFO (jetty-launcher-59-thread-1) [ ]
o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 216054 INFO (jetty-launcher-59-thread-1) [ ]
o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null, Default config
dir: null
[junit4] 2> 216054 INFO (jetty-launcher-59-thread-1) [ ]
o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time:
2017-10-08T07:29:41.699Z
[junit4] 2> 216055 INFO (jetty-launcher-59-thread-1) [ ]
o.a.s.c.SolrResourceLoader solr home defaulted to 'solr/' (could not find
system property or JNDI)
[junit4] 2> 216059 INFO (jetty-launcher-59-thread-1) [ ]
o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 216072 INFO (jetty-launcher-59-thread-1) [ ]
o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:61539/solr
[junit4] 2> 216077 WARN (NIOServerCxn.Factory:0.0.0.0/0.0.0.0:0) [ ]
o.a.z.s.NIOServerCnxn caught end of stream exception
[junit4] 2> EndOfStreamException: Unable to read additional data from
client sessionid 0x15efae3b8950002, likely client has closed socket
[junit4] 2> at
org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:239)
[junit4] 2> at
org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:203)
[junit4] 2> at java.lang.Thread.run(Thread.java:748)
[junit4] 2> 216228 INFO (jetty-launcher-59-thread-1)
[n:127.0.0.1:61543_solr ] o.a.s.c.Overseer Overseer (id=null) closing
[junit4] 2> 216229 INFO (jetty-launcher-59-thread-1)
[n:127.0.0.1:61543_solr ] o.a.s.c.OverseerElectionContext I am going to be
the leader 127.0.0.1:61543_solr
[junit4] 2> 216230 INFO (jetty-launcher-59-thread-1)
[n:127.0.0.1:61543_solr ] o.a.s.c.Overseer Overseer
(id=98792097810022403-127.0.0.1:61543_solr-n_0000000000) starting
[junit4] 2> 216240 INFO (jetty-launcher-59-thread-1)
[n:127.0.0.1:61543_solr ] o.a.s.c.ZkController Register node as live in
ZooKeeper:/live_nodes/127.0.0.1:61543_solr
[junit4] 2> 216240 DEBUG
(OverseerStateUpdate-98792097810022403-127.0.0.1:61543_solr-n_0000000000)
[n:127.0.0.1:61543_solr ] o.a.s.c.Overseer Starting to work on the main queue
[junit4] 2> 216241 DEBUG
(OverseerAutoScalingTriggerThread-98792097810022403-127.0.0.1:61543_solr-n_0000000000)
[n:127.0.0.1:61543_solr ] o.a.s.c.a.OverseerTriggerThread Adding
.autoAddReplicas trigger
[junit4] 2> 216244 DEBUG
(OverseerAutoScalingTriggerThread-98792097810022403-127.0.0.1:61543_solr-n_0000000000)
[n:127.0.0.1:61543_solr ] o.a.s.c.a.OverseerTriggerThread Refreshing
/autoscaling.json with znode version 1
[junit4] 2> 216245 INFO
(OverseerStateUpdate-98792097810022403-127.0.0.1:61543_solr-n_0000000000)
[n:127.0.0.1:61543_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (0) -> (1)
[junit4] 2> 216247 DEBUG
(OverseerAutoScalingTriggerThread-98792097810022403-127.0.0.1:61543_solr-n_0000000000)
[n:127.0.0.1:61543_solr ] o.a.s.c.a.NodeLostTrigger Initial livenodes:
[127.0.0.1:61543_solr]
[junit4] 2> 216247 DEBUG
(OverseerAutoScalingTriggerThread-98792097810022403-127.0.0.1:61543_solr-n_0000000000)
[n:127.0.0.1:61543_solr ] o.a.s.c.a.OverseerTriggerThread Current
znodeVersion 1, lastZnodeVersion -1
[junit4] 2> 216247 DEBUG
(OverseerAutoScalingTriggerThread-98792097810022403-127.0.0.1:61543_solr-n_0000000000)
[n:127.0.0.1:61543_solr ] o.a.s.c.a.OverseerTriggerThread Processed trigger
updates upto znodeVersion 1
[junit4] 2> 216250 DEBUG
(OverseerAutoScalingTriggerThread-98792097810022403-127.0.0.1:61543_solr-n_0000000000)
[n:127.0.0.1:61543_solr ] o.a.s.c.a.OverseerTriggerThread -- clean old
nodeAdded markers
[junit4] 2> 216250 DEBUG
(OverseerAutoScalingTriggerThread-98792097810022403-127.0.0.1:61543_solr-n_0000000000)
[n:127.0.0.1:61543_solr ] o.a.s.c.a.OverseerTriggerThread Current
znodeVersion 1, lastZnodeVersion 1
[junit4] 2> 216251 DEBUG (ScheduledTrigger-285-thread-1)
[n:127.0.0.1:61543_solr ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger:
.auto_add_replicas with currently live nodes: [127.0.0.1:61543_solr]
[junit4] 2> 216508 INFO (jetty-launcher-59-thread-1)
[n:127.0.0.1:61543_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for
'solr_61543.solr.node' (registry 'solr.node') enabled at server:
com.sun.jmx.mbeanserver.JmxMBeanServer@a7dd5f
[junit4] 2> 216529 INFO (jetty-launcher-59-thread-1)
[n:127.0.0.1:61543_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for
'solr_61543.solr.jvm' (registry 'solr.jvm') enabled at server:
com.sun.jmx.mbeanserver.JmxMBeanServer@a7dd5f
[junit4] 2> 216529 INFO (jetty-launcher-59-thread-1)
[n:127.0.0.1:61543_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for
'solr_61543.solr.jetty' (registry 'solr.jetty') enabled at server:
com.sun.jmx.mbeanserver.JmxMBeanServer@a7dd5f
[junit4] 2> 216531 INFO (jetty-launcher-59-thread-1)
[n:127.0.0.1:61543_solr ] o.a.s.c.CorePropertiesLocator Found 0 core
definitions underneath
C:\Users\jenkins\workspace\Lucene-Solr-master-Windows\solr\build\solr-core\test\J1\temp\solr.cloud.autoscaling.ComputePlanActionTest_B1DFD0131B7C99E4-001\tempDir-001\node1\.
[junit4] 2> 216560 WARN (NIOServerCxn.Factory:0.0.0.0/0.0.0.0:0) [ ]
o.a.z.s.NIOServerCnxn caught end of stream exception
[junit4] 2> EndOfStreamException: Unable to read additional data from
client sessionid 0x15efae3b8950004, likely client has closed socket
[junit4] 2> at
org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:239)
[junit4] 2> at
org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:203)
[junit4] 2> at java.lang.Thread.run(Thread.java:748)
[junit4] 2> 216567 INFO
(SUITE-ComputePlanActionTest-seed#[B1DFD0131B7C99E4]-worker) [ ]
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 216569 INFO
(SUITE-ComputePlanActionTest-seed#[B1DFD0131B7C99E4]-worker) [ ]
o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:61539/solr ready
[junit4] 2> 216581 INFO
(TEST-ComputePlanActionTest.testNodeAdded-seed#[B1DFD0131B7C99E4]) [ ]
o.a.s.SolrTestCaseJ4 ###Starting testNodeAdded
[junit4] 2> 216582 DEBUG
(zkCallback-66-thread-1-processing-n:127.0.0.1:61543_solr)
[n:127.0.0.1:61543_solr ] o.a.s.c.a.OverseerTriggerThread Refreshing
/autoscaling.json with znode version 2
[junit4] 2> 216582 DEBUG
(OverseerAutoScalingTriggerThread-98792097810022403-127.0.0.1:61543_solr-n_0000000000)
[n:127.0.0.1:61543_solr ] o.a.s.c.a.OverseerTriggerThread Processed trigger
updates upto znodeVersion 2
[junit4] 2> 216590 DEBUG
(OverseerAutoScalingTriggerThread-98792097810022403-127.0.0.1:61543_solr-n_0000000000)
[n:127.0.0.1:61543_solr ] o.a.s.c.a.OverseerTriggerThread -- clean old
nodeLost markers
[junit4] 2> 216592 DEBUG
(OverseerAutoScalingTriggerThread-98792097810022403-127.0.0.1:61543_solr-n_0000000000)
[n:127.0.0.1:61543_solr ] o.a.s.c.a.OverseerTriggerThread -- clean old
nodeAdded markers
[junit4] 2> 216593 DEBUG
(OverseerAutoScalingTriggerThread-98792097810022403-127.0.0.1:61543_solr-n_0000000000)
[n:127.0.0.1:61543_solr ] o.a.s.c.a.OverseerTriggerThread Current
znodeVersion 2, lastZnodeVersion 2
[junit4] 2> 216705 INFO (qtp14603425-1172) [n:127.0.0.1:61543_solr ]
o.a.s.h.a.CollectionsHandler Invoked Collection Action :delete with params
name=testNodeLost&action=DELETE&wt=javabin&version=2 and sendToOCPQueue=true
[junit4] 2> 216715 INFO
(OverseerThreadFactory-287-thread-1-processing-n:127.0.0.1:61543_solr)
[n:127.0.0.1:61543_solr ] o.a.s.c.OverseerCollectionMessageHandler Executing
Collection Cmd : action=UNLOAD&deleteInstanceDir=true&deleteDataDir=true
[junit4] 2> 216715 ERROR
(OverseerThreadFactory-287-thread-1-processing-n:127.0.0.1:61543_solr)
[n:127.0.0.1:61543_solr ] o.a.s.c.OverseerCollectionMessageHandler
Collection: testNodeLost operation: delete
failed:org.apache.solr.common.SolrException: Could not find collection :
testNodeLost
[junit4] 2> at
org.apache.solr.common.cloud.ClusterState.getCollection(ClusterState.java:111)
[junit4] 2> at
org.apache.solr.cloud.OverseerCollectionMessageHandler.collectionCmd(OverseerCollectionMessageHandler.java:798)
[junit4] 2> at
org.apache.solr.cloud.DeleteCollectionCmd.call(DeleteCollectionCmd.java:91)
[junit4] 2> at
org.apache.solr.cloud.OverseerCollectionMessageHandler.processMessage(OverseerCollectionMessageHandler.java:229)
[junit4] 2> at
org.apache.solr.cloud.OverseerTaskProcessor$Runner.run(OverseerTaskProcessor.java:464)
[junit4] 2> at
org.apache.solr.common.util.ExecutorUtil$MDCAwareThreadPoolExecutor.lambda$execute$0(ExecutorUtil.java:188)
[junit4] 2> at
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
[junit4] 2> at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
[junit4] 2> at java.lang.Thread.run(Thread.java:748)
[junit4] 2>
[junit4] 2> 216726 INFO (qtp14603425-1172) [n:127.0.0.1:61543_solr ]
o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections
params={name=testNodeLost&action=DELETE&wt=javabin&version=2} status=400
QTime=21
[junit4] 2> 216730 INFO (qtp14603425-1173) [n:127.0.0.1:61543_solr ]
o.a.s.h.a.CollectionsHandler Invoked Collection Action :delete with params
name=testNodeAdded&action=DELETE&wt=javabin&version=2 and sendToOCPQueue=true
[junit4] 2> 216734 INFO
(OverseerCollectionConfigSetProcessor-98792097810022403-127.0.0.1:61543_solr-n_0000000000)
[n:127.0.0.1:61543_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> 216734 INFO
(OverseerThreadFactory-287-thread-2-processing-n:127.0.0.1:61543_solr)
[n:127.0.0.1:61543_solr ] o.a.s.c.OverseerCollectionMessageHandler Executing
Collection Cmd : action=UNLOAD&deleteInstanceDir=true&deleteDataDir=true
[junit4] 2> 216735 ERROR
(OverseerThreadFactory-287-thread-2-processing-n:127.0.0.1:61543_solr)
[n:127.0.0.1:61543_solr ] o.a.s.c.OverseerCollectionMessageHandler
Collection: testNodeAdded operation: delete
failed:org.apache.solr.common.SolrException: Could not find collection :
testNodeAdded
[junit4] 2> at
org.apache.solr.common.cloud.ClusterState.getCollection(ClusterState.java:111)
[junit4] 2> at
org.apache.solr.cloud.OverseerCollectionMessageHandler.collectionCmd(OverseerCollectionMessageHandler.java:798)
[junit4] 2> at
org.apache.solr.cloud.DeleteCollectionCmd.call(DeleteCollectionCmd.java:91)
[junit4] 2> at
org.apache.solr.cloud.OverseerCollectionMessageHandler.processMessage(OverseerCollectionMessageHandler.java:229)
[junit4] 2> at
org.apache.solr.cloud.OverseerTaskProcessor$Runner.run(OverseerTaskProcessor.java:464)
[junit4] 2> at
org.apache.solr.common.util.ExecutorUtil$MDCAwareThreadPoolExecutor.lambda$execute$0(ExecutorUtil.java:188)
[junit4] 2> at
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
[junit4] 2> at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
[junit4] 2> at java.lang.Thread.run(Thread.java:748)
[junit4] 2>
[junit4] 2> 216738 INFO (qtp14603425-1173) [n:127.0.0.1:61543_solr ]
o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections
params={name=testNodeAdded&action=DELETE&wt=javabin&version=2} status=400
QTime=6
[junit4] 2> 216739 INFO (qtp14603425-1168) [n:127.0.0.1:61543_solr ]
o.a.s.h.a.CollectionsHandler Invoked Collection Action :delete with params
name=testNodeWithMultipleReplicasLost&action=DELETE&wt=javabin&version=2 and
sendToOCPQueue=true
[junit4] 2> 216743 INFO
(OverseerCollectionConfigSetProcessor-98792097810022403-127.0.0.1:61543_solr-n_0000000000)
[n:127.0.0.1:61543_solr ] o.a.s.c.OverseerTaskQueue Response ZK path:
/overseer/collection-queue-work/qnr-0000000002 doesn't exist. Requestor may
have disconnected from ZooKeeper
[junit4] 2> 216743 INFO
(OverseerThreadFactory-287-thread-3-processing-n:127.0.0.1:61543_solr)
[n:127.0.0.1:61543_solr ] o.a.s.c.OverseerCollectionMessageHandler Executing
Collection Cmd : action=UNLOAD&deleteInstanceDir=true&deleteDataDir=true
[junit4] 2> 216743 ERROR
(OverseerThreadFactory-287-thread-3-processing-n:127.0.0.1:61543_solr)
[n:127.0.0.1:61543_solr ] o.a.s.c.OverseerCollectionMessageHandler
Collection: testNodeWithMultipleReplicasLost operation: delete
failed:org.apache.solr.common.SolrException: Could not find collection :
testNodeWithMultipleReplicasLost
[junit4] 2> at
org.apache.solr.common.cloud.ClusterState.getCollection(ClusterState.java:111)
[junit4] 2> at
org.apache.solr.cloud.OverseerCollectionMessageHandler.collectionCmd(OverseerCollectionMessageHandler.java:798)
[junit4] 2> at
org.apache.solr.cloud.DeleteCollectionCmd.call(DeleteCollectionCmd.java:91)
[junit4] 2> at
org.apache.solr.cloud.OverseerCollectionMessageHandler.processMessage(OverseerCollectionMessageHandler.java:229)
[junit4] 2> at
org.apache.solr.cloud.OverseerTaskProcessor$Runner.run(OverseerTaskProcessor.java:464)
[junit4] 2> at
org.apache.solr.common.util.ExecutorUtil$MDCAwareThreadPoolExecutor.lambda$execute$0(ExecutorUtil.java:188)
[junit4] 2> at
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
[junit4] 2> at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
[junit4] 2> at java.lang.Thread.run(Thread.java:748)
[junit4] 2>
[junit4] 2> 216746 INFO (qtp14603425-1168) [n:127.0.0.1:61543_solr ]
o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections
params={name=testNodeWithMultipleReplicasLost&action=DELETE&wt=javabin&version=2}
status=400 QTime=6
[junit4] 2> 216794 INFO (qtp14603425-1170) [n:127.0.0.1:61543_solr ]
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 216795 INFO (qtp14603425-1170) [n:127.0.0.1:61543_solr ]
o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:61539/solr ready
[junit4] 2> 216818 INFO (qtp14603425-1174) [n:127.0.0.1:61543_solr ]
o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics
params={prefix=CORE.coreName&wt=javabin&version=2&group=solr.core} status=0
QTime=8
[junit4] 2> 216821 DEBUG (qtp14603425-1170) [n:127.0.0.1:61543_solr ]
o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
[junit4] 2> 216824 INFO (qtp14603425-1170) [n:127.0.0.1:61543_solr ]
o.a.s.s.HttpSolrCall [admin] webapp=null path=/cluster/autoscaling
params={wt=javabin&version=2} status=0 QTime=60
[junit4] 2> 216824 DEBUG
(zkCallback-66-thread-1-processing-n:127.0.0.1:61543_solr)
[n:127.0.0.1:61543_solr ] o.a.s.c.a.OverseerTriggerThread Refreshing
/autoscaling.json with znode version 3
[junit4] 2> 216824 DEBUG
(OverseerAutoScalingTriggerThread-98792097810022403-127.0.0.1:61543_solr-n_0000000000)
[n:127.0.0.1:61543_solr ] o.a.s.c.a.OverseerTriggerThread Processed trigger
updates upto znodeVersion 3
[junit4] 2> 216824 DEBUG
(OverseerAutoScalingTriggerThread-98792097810022403-127.0.0.1:61543_solr-n_0000000000)
[n:127.0.0.1:61543_solr ] o.a.s.c.a.OverseerTriggerThread -- clean old
nodeLost markers
[junit4] 2> 216826 DEBUG
(OverseerAutoScalingTriggerThread-98792097810022403-127.0.0.1:61543_solr-n_0000000000)
[n:127.0.0.1:61543_solr ] o.a.s.c.a.OverseerTriggerThread -- clean old
nodeAdded markers
[junit4] 2> 216826 DEBUG
(OverseerAutoScalingTriggerThread-98792097810022403-127.0.0.1:61543_solr-n_0000000000)
[n:127.0.0.1:61543_solr ] o.a.s.c.a.OverseerTriggerThread Current
znodeVersion 3, lastZnodeVersion 3
[junit4] 2> 216831 INFO (qtp14603425-1172) [n:127.0.0.1:61543_solr ]
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 216832 INFO (qtp14603425-1172) [n:127.0.0.1:61543_solr ]
o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:61539/solr ready
[junit4] 2> 216840 INFO (qtp14603425-1173) [n:127.0.0.1:61543_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=5
[junit4] 2> 216840 DEBUG (qtp14603425-1172) [n:127.0.0.1:61543_solr ]
o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
[junit4] 2> 216842 WARN (NIOServerCxn.Factory:0.0.0.0/0.0.0.0:0) [ ]
o.a.z.s.NIOServerCnxn caught end of stream exception
[junit4] 2> EndOfStreamException: Unable to read additional data from
client sessionid 0x15efae3b8950007, likely client has closed socket
[junit4] 2> at
org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:239)
[junit4] 2> at
org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:203)
[junit4] 2> at java.lang.Thread.run(Thread.java:748)
[junit4] 2> 216843 INFO (qtp14603425-1172) [n:127.0.0.1:61543_solr ]
o.a.s.s.HttpSolrCall [admin] webapp=null path=/cluster/autoscaling
params={wt=javabin&version=2} status=0 QTime=17
[junit4] 2> 216843 DEBUG
(zkCallback-66-thread-1-processing-n:127.0.0.1:61543_solr)
[n:127.0.0.1:61543_solr ] o.a.s.c.a.OverseerTriggerThread Refreshing
/autoscaling.json with znode version 4
[junit4] 2> 216843 DEBUG
(OverseerAutoScalingTriggerThread-98792097810022403-127.0.0.1:61543_solr-n_0000000000)
[n:127.0.0.1:61543_solr ] o.a.s.c.a.OverseerTriggerThread Processed trigger
updates upto znodeVersion 4
[junit4] 2> 216844 DEBUG
(OverseerAutoScalingTriggerThread-98792097810022403-127.0.0.1:61543_solr-n_0000000000)
[n:127.0.0.1:61543_solr ] o.a.s.c.a.OverseerTriggerThread -- clean old
nodeLost markers
[junit4] 2> 216844 DEBUG
(OverseerAutoScalingTriggerThread-98792097810022403-127.0.0.1:61543_solr-n_0000000000)
[n:127.0.0.1:61543_solr ] o.a.s.c.a.OverseerTriggerThread -- clean old
nodeAdded markers
[junit4] 2> 216845 DEBUG
(OverseerAutoScalingTriggerThread-98792097810022403-127.0.0.1:61543_solr-n_0000000000)
[n:127.0.0.1:61543_solr ] o.a.s.c.a.OverseerTriggerThread Current
znodeVersion 4, lastZnodeVersion 4
[junit4] 2> 216906 INFO (qtp14603425-1168) [n:127.0.0.1:61543_solr ]
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 216907 INFO (qtp14603425-1168) [n:127.0.0.1:61543_solr ]
o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:61539/solr ready
[junit4] 2> 216911 INFO (qtp14603425-1175) [n:127.0.0.1:61543_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> 216911 DEBUG (qtp14603425-1168) [n:127.0.0.1:61543_solr ]
o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
[junit4] 2> 216913 INFO (qtp14603425-1168) [n:127.0.0.1:61543_solr ]
o.a.s.s.HttpSolrCall [admin] webapp=null path=/cluster/autoscaling
params={wt=javabin&version=2} status=0 QTime=68
[junit4] 2> 216914 DEBUG
(zkCallback-66-thread-1-processing-n:127.0.0.1:61543_solr)
[n:127.0.0.1:61543_solr ] o.a.s.c.a.OverseerTriggerThread Refreshing
/autoscaling.json with znode version 5
[junit4] 2> 216920 INFO (qtp14603425-1171) [n:127.0.0.1:61543_solr ]
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 216921 INFO (qtp14603425-1171) [n:127.0.0.1:61543_solr ]
o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:61539/solr ready
[junit4] 2> 216924 DEBUG
(zkCallback-66-thread-1-processing-n:127.0.0.1:61543_solr)
[n:127.0.0.1:61543_solr ] o.a.s.c.a.NodeAddedTrigger Initial livenodes:
[127.0.0.1:61543_solr]
[junit4] 2> 216924 DEBUG
(zkCallback-66-thread-1-processing-n:127.0.0.1:61543_solr)
[n:127.0.0.1:61543_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> 216924 DEBUG
(OverseerAutoScalingTriggerThread-98792097810022403-127.0.0.1:61543_solr-n_0000000000)
[n:127.0.0.1:61543_solr ] o.a.s.c.a.OverseerTriggerThread Processed trigger
updates upto znodeVersion 5
[junit4] 2> 216924 INFO (qtp14603425-1174) [n:127.0.0.1:61543_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> 216924 DEBUG (qtp14603425-1171) [n:127.0.0.1:61543_solr ]
o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
[junit4] 2> 216926 INFO (qtp14603425-1171) [n:127.0.0.1:61543_solr ]
o.a.s.s.HttpSolrCall [admin] webapp=null path=/cluster/autoscaling
params={wt=javabin&version=2} status=0 QTime=11
[junit4] 2> 216928 DEBUG
(zkCallback-66-thread-1-processing-n:127.0.0.1:61543_solr)
[n:127.0.0.1:61543_solr ] o.a.s.c.a.OverseerTriggerThread Refreshing
/autoscaling.json with znode version 6
[junit4] 2> 216928 INFO (qtp14603425-1170) [n:127.0.0.1:61543_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> 216930 DEBUG
(OverseerAutoScalingTriggerThread-98792097810022403-127.0.0.1:61543_solr-n_0000000000)
[n:127.0.0.1:61543_solr ] o.a.s.c.a.OverseerTriggerThread -- clean old
nodeLost markers
[junit4] 2> 216930 DEBUG
(zkCallback-66-thread-1-processing-n:127.0.0.1:61543_solr)
[n:127.0.0.1:61543_solr ] o.a.s.c.a.NodeAddedTrigger Initial livenodes:
[127.0.0.1:61543_solr]
[junit4] 2> 216930 DEBUG
(zkCallback-66-thread-1-processing-n:127.0.0.1:61543_solr)
[n:127.0.0.1:61543_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> 216930 DEBUG (ScheduledTrigger-285-thread-1)
[n:127.0.0.1:61543_solr ] o.a.s.c.a.NodeAddedTrigger Running
NodeAddedTrigger node_added_trigger
[junit4] 2> 216931 DEBUG (ScheduledTrigger-285-thread-1)
[n:127.0.0.1:61543_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes:
[127.0.0.1:61543_solr]
[junit4] 2> 216931 DEBUG
(OverseerAutoScalingTriggerThread-98792097810022403-127.0.0.1:61543_solr-n_0000000000)
[n:127.0.0.1:61543_solr ] o.a.s.c.a.OverseerTriggerThread Current
znodeVersion 6, lastZnodeVersion 5
[junit4] 2> 216931 DEBUG
(OverseerAutoScalingTriggerThread-98792097810022403-127.0.0.1:61543_solr-n_0000000000)
[n:127.0.0.1:61543_solr ] o.a.s.c.a.OverseerTriggerThread Processed trigger
updates upto znodeVersion 6
[junit4] 2> 216931 DEBUG
(OverseerAutoScalingTriggerThread-98792097810022403-127.0.0.1:61543_solr-n_0000000000)
[n:127.0.0.1:61543_solr ] o.a.s.c.a.OverseerTriggerThread -- clean old
nodeLost markers
[junit4] 2> 216932 DEBUG
(OverseerAutoScalingTriggerThread-98792097810022403-127.0.0.1:61543_solr-n_0000000000)
[n:127.0.0.1:61543_solr ] o.a.s.c.a.OverseerTriggerThread Current
znodeVersion 6, lastZnodeVersion 6
[junit4] 2> 216933 INFO
(OverseerCollectionConfigSetProcessor-98792097810022403-127.0.0.1:61543_solr-n_0000000000)
[n:127.0.0.1:61543_solr ] o.a.s.c.OverseerTaskQueue Response ZK path:
/overseer/collection-queue-work/qnr-0000000004 doesn't exist. Requestor may
have disconnected from ZooKeeper
[junit4] 2> 216933 INFO
(OverseerThreadFactory-287-thread-4-processing-n:127.0.0.1:61543_solr)
[n:127.0.0.1:61543_solr ] o.a.s.c.CreateCollectionCmd Create collection
testNodeAdded
[junit4] 2> 216934 WARN
(OverseerThreadFactory-287-thread-4-processing-n:127.0.0.1:61543_solr)
[n:127.0.0.1:61543_solr ] o.a.s.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> 216947 INFO (qtp14603425-1175) [n:127.0.0.1:61543_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> 216964 DEBUG
(OverseerStateUpdate-98792097810022403-127.0.0.1:61543_solr-n_0000000000)
[n:127.0.0.1:61543_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> 216964 DEBUG
(OverseerStateUpdate-98792097810022403-127.0.0.1:61543_solr-n_0000000000)
[n:127.0.0.1:61543_solr ] o.a.s.c.o.ClusterStateMutator building a new
cName: testNodeAdded
[junit4] 2> 216966 DEBUG
(OverseerStateUpdate-98792097810022403-127.0.0.1:61543_solr-n_0000000000)
[n:127.0.0.1:61543_solr ] o.a.s.c.o.ZkStateWriter going to create_collection
/collections/testNodeAdded/state.json
[junit4] 2> 217080 DEBUG
(OverseerStateUpdate-98792097810022403-127.0.0.1:61543_solr-n_0000000000)
[n:127.0.0.1:61543_solr ] o.a.s.c.Overseer processMessage: queueSize: 1,
message = {
[junit4] 2> "operation":"ADDREPLICA",
[junit4] 2> "collection":"testNodeAdded",
[junit4] 2> "shard":"shard1",
[junit4] 2> "core":"testNodeAdded_shard1_replica_n1",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"https://127.0.0.1:61543/solr";,
[junit4] 2> "type":"NRT"} current state version: 0
[junit4] 2> 217080 INFO
(OverseerStateUpdate-98792097810022403-127.0.0.1:61543_solr-n_0000000000)
[n:127.0.0.1:61543_solr ] o.a.s.c.o.SliceMutator createReplica() {
[junit4] 2> "operation":"ADDREPLICA",
[junit4] 2> "collection":"testNodeAdded",
[junit4] 2> "shard":"shard1",
[junit4] 2> "core":"testNodeAdded_shard1_replica_n1",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"https://127.0.0.1:61543/solr";,
[junit4] 2> "type":"NRT"}
[junit4] 2> 217084 DEBUG
(OverseerStateUpdate-98792097810022403-127.0.0.1:61543_solr-n_0000000000)
[n:127.0.0.1:61543_solr ] o.a.s.c.o.SliceMutator Old Slice: shard1:{
[junit4] 2> "range":"80000000-7fffffff",
[junit4] 2> "state":"active",
[junit4] 2> "replicas":{}}
[junit4] 2> 217084 DEBUG
(OverseerStateUpdate-98792097810022403-127.0.0.1:61543_solr-n_0000000000)
[n:127.0.0.1:61543_solr ] o.a.s.c.o.SliceMutator New Slice: shard1:{
[junit4] 2> "range":"80000000-7fffffff",
[junit4] 2> "state":"active",
[junit4] 2> "replicas":{"core_node3":{
[junit4] 2> "core":"testNodeAdded_shard1_replica_n1",
[junit4] 2> "base_url":"https://127.0.0.1:61543/solr";,
[junit4] 2> "state":"down",
[junit4] 2> "node_name":null,
[junit4] 2> "type":"NRT"}}}
[junit4] 2> 217089 DEBUG
(OverseerStateUpdate-98792097810022403-127.0.0.1:61543_solr-n_0000000000)
[n:127.0.0.1:61543_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_n2",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"https://127.0.0.1:61543/solr";,
[junit4] 2> "type":"NRT"} current state version: 0
[junit4] 2> 217089 INFO
(OverseerStateUpdate-98792097810022403-127.0.0.1:61543_solr-n_0000000000)
[n:127.0.0.1:61543_solr ] o.a.s.c.o.SliceMutator createReplica() {
[junit4] 2> "operation":"ADDREPLICA",
[junit4] 2> "collection":"testNodeAdded",
[junit4] 2> "shard":"shard1",
[junit4] 2> "core":"testNodeAdded_shard1_replica_n2",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"https://127.0.0.1:61543/solr";,
[junit4] 2> "type":"NRT"}
[junit4] 2> 217093 DEBUG
(OverseerStateUpdate-98792097810022403-127.0.0.1:61543_solr-n_0000000000)
[n:127.0.0.1:61543_solr ] o.a.s.c.o.SliceMutator Old Slice: shard1:{
[junit4] 2> "range":"80000000-7fffffff",
[junit4] 2> "state":"active",
[junit4] 2> "replicas":{"core_node3":{
[junit4] 2> "core":"testNodeAdded_shard1_replica_n1",
[junit4] 2> "base_url":"https://127.0.0.1:61543/solr";,
[junit4] 2> "state":"down",
[junit4] 2> "node_name":null,
[junit4] 2> "type":"NRT"}}}
[junit4] 2> 217093 DEBUG
(OverseerStateUpdate-98792097810022403-127.0.0.1:61543_solr-n_0000000000)
[n:127.0.0.1:61543_solr ] o.a.s.c.o.SliceMutator New Slice: shard1:{
[junit4] 2> "range":"80000000-7fffffff",
[junit4] 2> "state":"active",
[junit4] 2> "replicas":{
[junit4] 2> "core_node3":{
[junit4] 2> "core":"testNodeAdded_shard1_replica_n1",
[junit4] 2> "base_url":"https://127.0.0.1:61543/solr";,
[junit4] 2> "state":"down",
[junit4] 2> "node_name":null,
[junit4] 2> "type":"NRT"},
[junit4] 2> "core_node4":{
[junit4] 2> "core":"testNodeAdded_shard1_replica_n2",
[junit4] 2> "base_url":"https://127.0.0.1:61543/solr";,
[junit4] 2> "state":"down",
[junit4] 2> "node_name":null,
[junit4] 2> "type":"NRT"}}}
[junit4] 2> 217200 DEBUG
(OverseerStateUpdate-98792097810022403-127.0.0.1:61543_solr-n_0000000000)
[n:127.0.0.1:61543_solr ] o.a.s.c.o.ZkStateWriter going to update_collection
/collections/testNodeAdded/state.json version: 0
[junit4] 2> 217302 INFO (qtp14603425-1174) [n:127.0.0.1:61543_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> 217302 INFO (qtp14603425-1172) [n:127.0.0.1:61543_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> 217305 INFO (qtp14603425-1172) [n:127.0.0.1:61543_solr ]
o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647
transient cores
[junit4] 2> 217322 DEBUG
(OverseerStateUpdate-98792097810022403-127.0.0.1:61543_solr-n_0000000000)
[n:127.0.0.1:61543_solr ] o.a.s.c.Overseer processMessage: queueSize: 2,
message = {
[junit4] 2> "core":"testNodeAdded_shard1_replica_n1",
[junit4] 2> "core_node_name":"core_node3",
[junit4] 2> "roles":null,
[junit4] 2> "base_url":"https://127.0.0.1:61543/solr";,
[junit4] 2> "node_name":"127.0.0.1:61543_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> 217323 DEBUG
(OverseerStateUpdate-98792097810022403-127.0.0.1:61543_solr-n_0000000000)
[n:127.0.0.1:61543_solr ] o.a.s.c.o.ReplicaMutator Update state numShards=1
message={
[junit4] 2> "core":"testNodeAdded_shard1_replica_n1",
[junit4] 2> "core_node_name":"core_node3",
[junit4] 2> "roles":null,
[junit4] 2> "base_url":"https://127.0.0.1:61543/solr";,
[junit4] 2> "node_name":"127.0.0.1:61543_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> 217323 DEBUG
(OverseerStateUpdate-98792097810022403-127.0.0.1:61543_solr-n_0000000000)
[n:127.0.0.1:61543_solr ] o.a.s.c.o.ReplicaMutator Will update state for
replica:
core_node3:{"core":"testNodeAdded_shard1_replica_n1","base_url":"https://127.0.0.1:61543/solr","node_name":"127.0.0.1:61543_solr","state":"down","type":"NRT"}
[junit4] 2> 217323 DEBUG
(OverseerStateUpdate-98792097810022403-127.0.0.1:61543_solr-n_0000000000)
[n:127.0.0.1:61543_solr ] o.a.s.c.o.ReplicaMutator Collection is now:
DocCollection(testNodeAdded//collections/testNodeAdded/state.json/1)={
[junit4] 2> "pullReplicas":"0",
[junit4] 2> "replicationFactor":"2",
[junit4] 2> "router":{"name":"compositeId"},
[junit4] 2> "maxShardsPerNode":"1",
[junit4] 2> "autoAddReplicas":"false",
[junit4] 2> "nrtReplicas":"2",
[junit4] 2> "tlogReplicas":"0",
[junit4] 2> "shards":{"shard1":{
[junit4] 2> "range":"80000000-7fffffff",
[junit4] 2> "state":"active",
[junit4] 2> "replicas":{
[junit4] 2> "core_node3":{
[junit4] 2> "core":"testNodeAdded_shard1_replica_n1",
[junit4] 2> "base_url":"https://127.0.0.1:61543/solr";,
[junit4] 2> "node_name":"127.0.0.1:61543_solr",
[junit4] 2> "state":"down",
[junit4] 2> "type":"NRT"},
[junit4] 2> "core_node4":{
[junit4] 2> "core":"testNodeAdded_shard1_replica_n2",
[junit4] 2> "base_url":"https://127.0.0.1:61543/solr";,
[junit4] 2> "state":"down",
[junit4] 2> "node_name":null,
[junit4] 2> "type":"NRT"}}}}}
[junit4] 2> 217326 DEBUG
(OverseerStateUpdate-98792097810022403-127.0.0.1:61543_solr-n_0000000000)
[n:127.0.0.1:61543_solr ] o.a.s.c.Overseer processMessage: queueSize: 1,
message = {
[junit4] 2> "core":"testNodeAdded_shard1_replica_n2",
[junit4] 2> "core_node_name":"core_node4",
[junit4] 2> "roles":null,
[junit4] 2> "base_url":"https://127.0.0.1:61543/solr";,
[junit4] 2> "node_name":"127.0.0.1:61543_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> 217327 DEBUG
(OverseerStateUpdate-98792097810022403-127.0.0.1:61543_solr-n_0000000000)
[n:127.0.0.1:61543_solr ] o.a.s.c.o.ReplicaMutator Update state numShards=1
message={
[junit4] 2> "core":"testNodeAdded_shard1_replica_n2",
[junit4] 2> "core_node_name":"core_node4",
[junit4] 2> "roles":null,
[junit4] 2> "base_url":"https://127.0.0.1:61543/solr";,
[junit4] 2> "node_name":"127.0.0.1:61543_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> 217327 DEBUG
(OverseerStateUpdate-98792097810022403-127.0.0.1:61543_solr-n_0000000000)
[n:127.0.0.1:61543_solr ] o.a.s.c.o.ReplicaMutator Will update state for
replica:
core_node4:{"core":"testNodeAdded_shard1_replica_n2","base_url":"https://127.0.0.1:61543/solr","node_name":"127.0.0.1:61543_solr","state":"down","type":"NRT"}
[junit4] 2> 217327 DEBUG
(OverseerStateUpdate-98792097810022403-127.0.0.1:61543_solr-n_0000000000)
[n:127.0.0.1:61543_solr ] o.a.s.c.o.ReplicaMutator Collection is now:
DocCollection(testNodeAdded//collections/testNodeAdded/state.json/1)={
[junit4] 2> "pullReplicas":"0",
[junit4] 2> "replicationFactor":"2",
[junit4] 2> "router":{"name":"compositeId"},
[junit4] 2> "maxShardsPerNode":"1",
[junit4] 2> "autoAddReplicas":"false",
[junit4] 2> "nrtReplicas":"2",
[junit4] 2> "tlogReplicas":"0",
[junit4] 2> "shards":{"shard1":{
[junit4] 2> "range":"80000000-7fffffff",
[junit4] 2> "state":"active",
[junit4] 2> "replicas":{
[junit4] 2> "core_node3":{
[junit4] 2> "core":"testNodeAdded_shard1_replica_n1",
[junit4] 2> "base_url":"https://127.0.0.1:61543/solr";,
[junit4] 2> "node_name":"127.0.0.1:61543_solr",
[junit4] 2> "state":"down",
[junit4] 2> "type":"NRT"},
[junit4] 2> "core_node4":{
[junit4] 2> "core":"testNodeAdded_shard1_replica_n2",
[junit4] 2> "base_url":"https://127.0.0.1:61543/solr";,
[junit4] 2> "node_name":"127.0.0.1:61543_solr",
[junit4] 2> "state":"down",
[junit4] 2> "type":"NRT"}}}}}
[junit4] 2> 217431 DEBUG
(OverseerStateUpdate-98792097810022403-127.0.0.1:61543_solr-n_0000000000)
[n:127.0.0.1:61543_solr ] o.a.s.c.o.ZkStateWriter going to update_collection
/collections/testNodeAdded/state.json version: 1
[junit4] 2> 217433 INFO
(zkCallback-66-thread-1-processing-n:127.0.0.1:61543_solr)
[n:127.0.0.1:61543_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> 217433 INFO
(zkCallback-66-thread-2-processing-n:127.0.0.1:61543_solr)
[n:127.0.0.1:61543_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> 217934 DEBUG (ScheduledTrigger-285-thread-2)
[n:127.0.0.1:61543_solr ] o.a.s.c.a.NodeAddedTrigger Running
NodeAddedTrigger node_added_trigger
[junit4] 2> 217934 DEBUG (ScheduledTrigger-285-thread-2)
[n:127.0.0.1:61543_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes:
[127.0.0.1:61543_solr]
[junit4] 2> 218351 INFO (qtp14603425-1174) [n:127.0.0.1:61543_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> 218351 INFO (qtp14603425-1172) [n:127.0.0.1:61543_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> 218363 INFO (qtp14603425-1172) [n:127.0.0.1:61543_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> 218363 INFO (qtp14603425-1174) [n:127.0.0.1:61543_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> 218369 INFO (qtp14603425-1172) [n:127.0.0.1:61543_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> 218369 INFO (qtp14603425-1174) [n:127.0.0.1:61543_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> 218369 INFO (qtp14603425-1174) [n:127.0.0.1:61543_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> 218369 INFO (qtp14603425-1172) [n:127.0.0.1:61543_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> 218371 INFO (qtp14603425-1172) [n:127.0.0.1:61543_solr
c:testNodeAdded s:shard1 r:core_node4 x:testNodeAdded_shard1_replica_n2]
o.a.s.m.r.SolrJmxReporter JMX monitoring for
'solr_61543.solr.core.testNodeAdded.shard1.replica_n2' (registry
'solr.core.testNodeAdded.shard1.replica_n2') enabled at server:
com.sun.jmx.mbeanserver.JmxMBeanServer@a7dd5f
[junit4] 2> 218371 INFO (qtp14603425-1174) [n:127.0.0.1:61543_solr
c:testNodeAdded s:shard1 r:core_node3 x:testNodeAdded_shard1_replica_n1]
o.a.s.m.r.SolrJmxReporter JMX monitoring for
'solr_61543.solr.core.testNodeAdded.shard1.replica_n1' (registry
'solr.core.testNodeAdded.shard1.replica_n1') enabled at server:
com.sun.jmx.mbeanserver.JmxMBeanServer@a7dd5f
[junit4] 2> 218371 INFO (qtp14603425-1172) [n:127.0.0.1:61543_solr
c:testNodeAdded s:shard1 r:core_node4 x:testNodeAdded_shard1_replica_n2]
o.a.s.c.SolrCore solr.RecoveryStrategy.Builder
[junit4] 2> 218371 INFO (qtp14603425-1174) [n:127.0.0.1:61543_solr
c:testNodeAdded s:shard1 r:core_node3 x:testNodeAdded_shard1_replica_n1]
o.a.s.c.SolrCore solr.RecoveryStrategy.Builder
[junit4] 2> 218371 INFO (qtp14603425-1172) [n:127.0.0.1:61543_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
[C:\Users\jenkins\workspace\Lucene-Solr-master-Windows\solr\build\solr-core\test\J1\temp\solr.cloud.autoscaling.ComputePlanActionTest_B1DFD0131B7C99E4-001\tempDir-001\node1\testNodeAdded_shard1_replica_n2],
dataDir=[C:\Users\jenkins\workspace\Lucene-Solr-master-Windows\solr\build\solr-core\test\J1\temp\solr.cloud.autoscaling.ComputePlanActionTest_B1DFD0131B7C99E4-001\tempDir-001\node1\.\testNodeAdded_shard1_replica_n2\data\]
[junit4] 2> 218371 INFO (qtp14603425-1174) [n:127.0.0.1:61543_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
[C:\Users\jenkins\workspace\Lucene-Solr-master-Windows\solr\build\solr-core\test\J1\temp\solr.cloud.autoscaling.ComputePlanActionTest_B1DFD0131B7C99E4-001\tempDir-001\node1\testNodeAdded_shard1_replica_n1],
dataDir=[C:\Users\jenkins\workspace\Lucene-Solr-master-Windows\solr\build\solr-core\test\J1\temp\solr.cloud.autoscaling.ComputePlanActionTest_B1DFD0131B7C99E4-001\tempDir-001\node1\.\testNodeAdded_shard1_replica_n1\data\]
[junit4] 2> 218518 INFO (qtp14603425-1174) [n:127.0.0.1:61543_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> 218518 INFO (qtp14603425-1174) [n:127.0.0.1:61543_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> 218518 INFO (qtp14603425-1172) [n:127.0.0.1:61543_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> 218518 INFO (qtp14603425-1172) [n:127.0.0.1:61543_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> 218521 INFO (qtp14603425-1172) [n:127.0.0.1:61543_solr
c:testNodeAdded s:shard1 r:core_node4 x:testNodeAdded_shard1_replica_n2]
o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 218521 INFO (qtp14603425-1174) [n:127.0.0.1:61543_solr
c:testNodeAdded s:shard1 r:core_node3 x:testNodeAdded_shard1_replica_n1]
o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 218521 INFO (qtp14603425-1174) [n:127.0.0.1:61543_solr
c:testNodeAdded s:shard1 r:core_node3 x:testNodeAdded_shard1_replica_n1]
o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 218521 INFO (qtp14603425-1172) [n:127.0.0.1:61543_solr
c:testNodeAdded s:shard1 r:core_node4 x:testNodeAdded_shard1_replica_n2]
o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 218523 INFO (qtp14603425-1174) [n:127.0.0.1:61543_solr
c:testNodeAdded s:shard1 r:core_node3 x:testNodeAdded_shard1_replica_n1]
o.a.s.s.SolrIndexSearcher Opening
[Searcher@1025cb[testNodeAdded_shard1_replica_n1] main]
[junit4] 2> 218523 INFO (qtp14603425-1172) [n:127.0.0.1:61543_solr
c:testNodeAdded s:shard1 r:core_node4 x:testNodeAdded_shard1_replica_n2]
o.a.s.s.SolrIndexSearcher Opening
[Searcher@9aa740[testNodeAdded_shard1_replica_n2] main]
[junit4] 2> 218525 INFO (qtp14603425-1174) [n:127.0.0.1:61543_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> 218525 INFO (qtp14603425-1172) [n:127.0.0.1:61543_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> 218525 INFO (qtp14603425-1174) [n:127.0.0.1:61543_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> 218525 INFO (qtp14603425-1172) [n:127.0.0.1:61543_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> 218527 INFO (qtp14603425-1174) [n:127.0.0.1:61543_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> 218527 INFO (qtp14603425-1172) [n:127.0.0.1:61543_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> 218528 INFO (qtp14603425-1174) [n:127.0.0.1:61543_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 1580673567736987648
[junit4] 2> 218529 INFO
(searcherExecutor-290-thread-1-processing-n:127.0.0.1:61543_solr
x:testNodeAdded_shard1_replica_n1 s:shard1 c:testNodeAdded r:core_node3)
[n:127.0.0.1:61543_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@1025cb[testNodeAdded_shard1_replica_n1]
main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 218529 INFO (qtp14603425-1172) [n:127.0.0.1:61543_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 1580673567738036224
[junit4] 2> 218533 INFO
(searcherExecutor-291-thread-1-processing-n:127.0.0.1:61543_solr
x:testNodeAdded_shard1_replica_n2 s:shard1 c:testNodeAdded r:core_node4)
[n:127.0.0.1:61543_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@9aa740[testNodeAdded_shard1_replica_n2]
main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 218538 INFO (qtp14603425-1172) [n:127.0.0.1:61543_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> 218538 INFO (qtp14603425-1172) [n:127.0.0.1:61543_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> 218538 INFO (qtp14603425-1172) [n:127.0.0.1:61543_solr
c:testNodeAdded s:shard1 r:core_node4 x:testNodeAdded_shard1_replica_n2]
o.a.s.c.SyncStrategy Sync replicas to
https://127.0.0.1:61543/solr/testNodeAdded_shard1_replica_n2/
[junit4] 2> 218539 DEBUG
(OverseerStateUpdate-98792097810022403-127.0.0.1:61543_solr-n_0000000000)
[n:127.0.0.1:61543_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> 218547 INFO (qtp14603425-1172) [n:127.0.0.1:61543_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=https://127.0.0.1:61543/solr START
replicas=[https://127.0.0.1:61543/solr/testNodeAdded_shard1_replica_n1/]
nUpdates=100
[junit4] 2> 218549 INFO (qtp14603425-1173) [n:127.0.0.1:61543_solr
c:testNodeAdded s:shard1 r:core_node3 x:testNodeAdded_shard1_replica_n1]
o.a.s.c.S.Request [testNodeAdded_shard1_replica_n1] webapp=/solr path=/get
params={distrib=false&qt=/get&fingerprint=false&getVersions=100&wt=javabin&version=2}
status=0 QTime=0
[junit4] 2> 218643 DEBUG
(OverseerStateUpdate-98792097810022403-127.0.0.1:61543_solr-n_0000000000)
[n:127.0.0.1:61543_solr ] o.a.s.c.o.ZkStateWriter going to update_collection
/collections/testNodeAdded/state.json version: 2
[junit4] 2> 218645 INFO
(zkCallback-66-thread-2-processing-n:127.0.0.1:61543_solr)
[n:127.0.0.1:61543_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> 218645 INFO
(zkCallback-66-thread-1-processing-n:127.0.0.1:61543_solr)
[n:127.0.0.1:61543_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> 218848 INFO (qtp14603425-1172) [n:127.0.0.1:61543_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=https://127.0.0.1:61543/solr DONE. We have no versions. sync failed.
[junit4] 2> 218848 INFO (qtp14603425-1172) [n:127.0.0.1:61543_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> 218848 INFO (qtp14603425-1172) [n:127.0.0.1:61543_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> 218848 INFO (qtp14603425-1172) [n:127.0.0.1:61543_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> 218863 INFO (qtp14603425-1172) [n:127.0.0.1:61543_solr
c:testNodeAdded s:shard1 r:core_node4 x:testNodeAdded_shard1_replica_n2]
o.a.s.c.ShardLeaderElectionContext I am the new leader:
https://127.0.0.1:61543/solr/testNodeAdded_shard1_replica_n2/ shard1
[junit4] 2> 218865 DEBUG
(OverseerStateUpdate-98792097810022403-127.0.0.1:61543_solr-n_0000000000)
[n:127.0.0.1:61543_solr ] o.a.s.c.Overseer processMessage: queueSize: 1,
message = {
[junit4] 2> "operation":"leader",
[junit4] 2> "shard":"shard1",
[junit4] 2> "collection":"testNodeAdded",
[junit4] 2> "base_url":"https://127.0.0.1:61543/solr";,
[junit4] 2> "core":"testNodeAdded_shard1_replica_n2"} current state
version: 0
[junit4] 2> 218935 DEBUG (ScheduledTrigger-285-thread-2)
[n:127.0.0.1:61543_solr ] o.a.s.c.a.NodeAddedTrigger Running
NodeAddedTrigger node_added_trigger
[junit4] 2> 218935 DEBUG (ScheduledTrigger-285-thread-2)
[n:127.0.0.1:61543_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes:
[127.0.0.1:61543_solr]
[junit4] 2> 218970 DEBUG
(OverseerStateUpdate-98792097810022403-127.0.0.1:61543_solr-n_0000000000)
[n:127.0.0.1:61543_solr ] o.a.s.c.o.ZkStateWriter going to update_collection
/collections/testNodeAdded/state.json version: 3
[junit4] 2> 218971 INFO
(zkCallback-66-thread-2-processing-n:127.0.0.1:61543_solr)
[n:127.0.0.1:61543_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> 218971 INFO
(zkCallback-66-thread-1-processing-n:127.0.0.1:61543_solr)
[n:127.0.0.1:61543_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> 219016 INFO (qtp14603425-1172) [n:127.0.0.1:61543_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> 219020 INFO (qtp14603425-1172) [n:127.0.0.1:61543_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=1718
[junit4] 2> 219022 DEBUG
(OverseerStateUpdate-98792097810022403-127.0.0.1:61543_solr-n_0000000000)
[n:127.0.0.1:61543_solr ] o.a.s.c.Overseer processMessage: queueSize: 1,
message = {
[junit4] 2> "core":"testNodeAdded_shard1_replica_n2",
[junit4] 2> "core_node_name":"core_node4",
[junit4] 2> "roles":null,
[junit4] 2> "base_url":"https://127.0.0.1:61543/solr";,
[junit4] 2> "node_name":"127.0.0.1:61543_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> 219022 DEBUG
(OverseerStateUpdate-98792097810022403-127.0.0.1:61543_solr-n_0000000000)
[n:127.0.0.1:61543_solr ] o.a.s.c.o.ReplicaMutator Update state numShards=1
message={
[junit4] 2> "core":"testNodeAdded_shard1_replica_n2",
[junit4] 2> "core_node_name":"core_node4",
[junit4] 2> "roles":null,
[junit4] 2> "base_url":"https://127.0.0.1:61543/solr";,
[junit4] 2> "node_name":"127.0.0.1:61543_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> 219022 DEBUG
(OverseerStateUpdate-98792097810022403-127.0.0.1:61543_solr-n_0000000000)
[n:127.0.0.1:61543_solr ] o.a.s.c.o.ReplicaMutator Will update state for
replica:
core_node4:{"core":"testNodeAdded_shard1_replica_n2","base_url":"https://127.0.0.1:61543/solr","node_name":"127.0.0.1:61543_solr","state":"active","type":"NRT","leader":"true"}
[junit4] 2> 219022 DEBUG
(OverseerStateUpdate-98792097810022403-127.0.0.1:61543_solr-n_0000000000)
[n:127.0.0.1:61543_solr ] o.a.s.c.o.ReplicaMutator Collection is now:
DocCollection(testNodeAdded//collections/testNodeAdded/state.json/4)={
[junit4] 2> "pullReplicas":"0",
[junit4] 2> "replicationFactor":"2",
[junit4] 2> "router":{"name":"compositeId"},
[junit4] 2> "maxShardsPerNode":"1",
[junit4] 2> "autoAddReplicas":"false",
[junit4] 2> "nrtReplicas":"2",
[junit4] 2> "tlogReplicas":"0",
[junit4] 2> "shards":{"shard1":{
[junit4] 2> "range":"80000000-7fffffff",
[junit4] 2> "state":"active",
[junit4] 2> "replicas":{
[junit4] 2> "core_node3":{
[junit4] 2> "core":"testNodeAdded_shard1_replica_n1",
[junit4] 2> "base_url":"https://127.0.0.1:61543/solr";,
[junit4] 2> "node_name":"127.0.0.1:61543_solr",
[junit4] 2> "state":"down",
[junit4] 2> "type":"NRT"},
[junit4] 2> "core_node4":{
[junit4] 2> "core":"testNodeAdded_shard1_replica_n2",
[junit4] 2> "base_url":"https://127.0.0.1:61543/solr";,
[junit4] 2> "node_name":"127.0.0.1:61543_solr",
[junit4] 2> "state":"active",
[junit4] 2> "type":"NRT",
[junit4] 2> "leader":"true"}}}}}
[junit4] 2> 219129 DEBUG
(OverseerStateUpdate-98792097810022403-127.0.0.1:61543_solr-n_0000000000)
[n:127.0.0.1:61543_solr ] o.a.s.c.o.ZkStateWriter going to update_collection
/collections/testNodeAdded/state.json version: 4
[junit4] 2> 219130 INFO
(zkCallback-66-thread-2-processing-n:127.0.0.1:61543_solr)
[n:127.0.0.1:61543_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> 219130 INFO
(zkCallback-66-thread-1-processing-n:127.0.0.1:61543_solr)
[n:127.0.0.1:61543_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> 219543 INFO (qtp14603425-1174) [n:127.0.0.1:61543_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=2241
[junit4] 2> 219544 DEBUG
(OverseerStateUpdate-98792097810022403-127.0.0.1:61543_solr-n_0000000000)
[n:127.0.0.1:61543_solr ] o.a.s.c.Overseer processMessage: queueSize: 1,
message = {
[junit4] 2> "core":"testNodeAdded_shard1_replica_n1",
[junit4] 2> "core_node_name":"core_node3",
[junit4] 2> "roles":null,
[junit4] 2> "base_url":"https://127.0.0.1:61543/solr";,
[junit4] 2> "node_name":"127.0.0.1:61543_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> 219544 DEBUG
(OverseerStateUpdate-98792097810022403-127.0.0.1:61543_solr-n_0000000000)
[n:127.0.0.1:61543_solr ] o.a.s.c.o.ReplicaMutator Update state numShards=1
message={
[junit4] 2> "core":"testNodeAdded_shard1_replica_n1",
[junit4] 2> "core_node_name":"core_node3",
[junit4] 2> "roles":null,
[junit4] 2> "base_url":"https://127.0.0.1:61543/solr";,
[junit4] 2> "node_name":"127.0.0.1:61543_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> 219545 DEBUG
(OverseerStateUpdate-98792097810022403-127.0.0.1:61543_solr-n_0000000000)
[n:127.0.0.1:61543_solr ] o.a.s.c.o.ReplicaMutator Will update state for
replica:
core_node3:{"core":"testNodeAdded_shard1_replica_n1","base_url":"https://127.0.0.1:61543/solr","node_name":"127.0.0.1:61543_solr","state":"active","type":"NRT"}
[junit4] 2> 219545 DEBUG
(OverseerStateUpdate-98792097810022403-127.0.0.1:61543_solr-n_0000000000)
[n:127.0.0.1:61543_solr ] o.a.s.c.o.ReplicaMutator Collection is now:
DocCollection(testNodeAdded//collections/testNodeAdded/state.json/5)={
[junit4] 2> "pullReplicas":"0",
[junit4] 2> "replicationFactor":"2",
[junit4] 2> "router":{"name":"compositeId"},
[junit4] 2> "maxShardsPerNode":"1",
[junit4] 2> "autoAddReplicas":"false",
[junit4] 2> "nrtReplicas":"2",
[junit4] 2> "tlogReplicas":"0",
[junit4] 2> "shards":{"shard1":{
[junit4] 2> "range":"80000000-7fffffff",
[junit4] 2> "state":"active",
[junit4] 2> "replicas":{
[junit4] 2> "core_node3":{
[junit4] 2> "core":"testNodeAdded_shard1_replica_n1",
[junit4] 2> "base_url":"https://127.0.0.1:61543/solr";,
[junit4] 2> "node_name":"127.0.0.1:61543_solr",
[junit4] 2> "state":"active",
[junit4] 2> "type":"NRT"},
[junit4] 2> "core_node4":{
[junit4] 2> "core":"testNodeAdded_shard1_replica_n2",
[junit4] 2> "base_url":"https://127.0.0.1:61543/solr";,
[junit4] 2> "node_name":"127.0.0.1:61543_solr",
[junit4] 2> "state":"active",
[junit4] 2> "type":"NRT",
[junit4] 2> "leader":"true"}}}}}
[junit4] 2> 219552 INFO (qtp14603425-1170) [n:127.0.0.1:61543_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> 219654 DEBUG
(OverseerStateUpdate-98792097810022403-127.0.0.1:61543_solr-n_0000000000)
[n:127.0.0.1:61543_solr ] o.a.s.c.o.ZkStateWriter going to update_collection
/collections/testNodeAdded/state.json version: 5
[junit4] 2> 219656 INFO
(zkCallback-66-thread-1-processing-n:127.0.0.1:61543_solr)
[n:127.0.0.1:61543_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> 219656 INFO
(zkCallback-66-thread-2-processing-n:127.0.0.1:61543_solr)
[n:127.0.0.1:61543_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> 219936 DEBUG (ScheduledTrigger-285-thread-1)
[n:127.0.0.1:61543_solr ] o.a.s.c.a.NodeAddedTrigger Running
NodeAddedTrigger node_added_trigger
[junit4] 2> 219936 DEBUG (ScheduledTrigger-285-thread-1)
[n:127.0.0.1:61543_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes:
[127.0.0.1:61543_solr]
[junit4] 2> 220552 INFO (qtp14603425-1170) [n:127.0.0.1:61543_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=3624
[junit4] 2> 220572 INFO (qtp14603425-1175) [n:127.0.0.1:61543_solr ]
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 220575 INFO (qtp14603425-1175) [n:127.0.0.1:61543_solr ]
o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:61539/solr ready
[junit4] 2> 220595 INFO (qtp14603425-1168) [n:127.0.0.1:61543_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=7
[junit4] 2> 220599 DEBUG (qtp14603425-1175) [n:127.0.0.1:61543_solr ]
o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
[junit4] 2> 220600 WARN (NIOServerCxn.Factory:0.0.0.0/0.0.0.0:0) [ ]
o.a.z.s.NIOServerCnxn caught end of stream exception
[junit4] 2> EndOfStreamException: Unable to read additional data from
client sessionid 0x15efae3b895000a, likely client has closed socket
[junit4] 2> at
org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:239)
[junit4] 2> at
org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:203)
[junit4] 2> at java.lang.Thread.run(Thread.java:748)
[junit4] 2> 220601 INFO (qtp14603425-1175) [n:127.0.0.1:61543_solr ]
o.a.s.s.HttpSolrCall [admin] webapp=null path=/cluster/autoscaling
params={wt=javabin&version=2} status=0 QTime=41
[junit4] 2> 220601 DEBUG
(zkCallback-66-thread-2-processing-n:127.0.0.1:61543_solr)
[n:127.0.0.1:61543_solr ] o.a.s.c.a.OverseerTriggerThread Refreshing
/autoscaling.json with znode version 7
[junit4] 2> 220604 DEBUG
(zkCallback-66-thread-2-processing-n:127.0.0.1:61543_solr)
[n:127.0.0.1:61543_solr ] o.a.s.c.a.NodeAddedTrigger Initial livenodes:
[127.0.0.1:61543_solr]
[junit4] 2> 220604 DEBUG
(zkCallback-66-thread-2-processing-n:127.0.0.1:61543_solr)
[n:127.0.0.1:61543_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> 220604 DEBUG
(OverseerAutoScalingTriggerThread-98792097810022403-127.0.0.1:61543_solr-n_0000000000)
[n:127.0.0.1:61543_solr ] o.a.s.c.a.OverseerTriggerThread Processed trigger
updates upto znodeVersion 7
[junit4] 2> 220604 DEBUG
(OverseerAutoScalingTriggerThread-98792097810022403-127.0.0.1:61543_solr-n_0000000000)
[n:127.0.0.1:61543_solr ] o.a.s.c.a.OverseerTriggerThread -- clean old
nodeLost markers
[junit4] 2> 220604 DEBUG
(OverseerAutoScalingTriggerThread-98792097810022403-127.0.0.1:61543_solr-n_0000000000)
[n:127.0.0.1:61543_solr ] o.a.s.c.a.OverseerTriggerThread Current
znodeVersion 7, lastZnodeVersion 7
[junit4] 2> 220606 INFO
(TEST-ComputePlanActionTest.testNodeAdded-seed#[B1DFD0131B7C99E4]) [ ]
o.e.j.s.Server jetty-9.3.20.v20170531
[junit4] 2> 220608 INFO
(TEST-ComputePlanActionTest.testNodeAdded-seed#[B1DFD0131B7C99E4]) [ ]
o.e.j.s.h.ContextHandler Started
o.e.j.s.ServletContextHandler@7181c0{/solr,null,AVAILABLE}
[junit4] 2> 220609 INFO
(TEST-ComputePlanActionTest.testNodeAdded-seed#[B1DFD0131B7C99E4]) [ ]
o.e.j.s.AbstractConnector Started ServerConnector@14c5e03{SSL,[ssl,
http/1.1]}{127.0.0.1:61583}
[junit4] 2> 220609 INFO
(TEST-ComputePlanActionTest.testNodeAdded-seed#[B1DFD0131B7C99E4]) [ ]
o.e.j.s.Server Started @227960ms
[junit4] 2> 220609 INFO
(TEST-ComputePlanActionTest.testNodeAdded-seed#[B1DFD0131B7C99E4]) [ ]
o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr,
hostPort=61583}
[junit4] 2> 220609 ERROR
(TEST-ComputePlanActionTest.testNodeAdded-seed#[B1DFD0131B7C99E4]) [ ]
o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be
missing or incomplete.
[junit4] 2> 220609 INFO
(TEST-ComputePlanActionTest.testNodeAdded-seed#[B1DFD0131B7C99E4]) [ ]
o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr™ version
8.0.0
[junit4] 2> 220611 INFO
(TEST-ComputePlanActionTest.testNodeAdded-seed#[B1DFD0131B7C99E4]) [ ]
o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 220611 INFO
(TEST-ComputePlanActionTest.testNodeAdded-seed#[B1DFD0131B7C99E4]) [ ]
o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null, Default config
dir: null
[junit4] 2> 220611 INFO
(TEST-ComputePlanActionTest.testNodeAdded-seed#[B1DFD0131B7C99E4]) [ ]
o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time:
2017-10-08T07:29:46.256Z
[junit4] 2> 220615 INFO
(TEST-ComputePlanActionTest.testNodeAdded-seed#[B1DFD0131B7C99E4]) [ ]
o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 220633 INFO
(TEST-ComputePlanActionTest.testNodeAdded-seed#[B1DFD0131B7C99E4]) [ ]
o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:61539/solr
[junit4] 2> 220637 WARN (NIOServerCxn.Factory:0.0.0.0/0.0.0.0:0) [ ]
o.a.z.s.NIOServerCnxn caught end of stream exception
[junit4] 2> EndOfStreamException: Unable to read additional data from
client sessionid 0x15efae3b895000c, likely client has closed socket
[junit4] 2> at
org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:239)
[junit4] 2> at
org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:203)
[junit4] 2> at java.lang.Thread.run(Thread.java:748)
[junit4] 2> 220650 INFO
(TEST-ComputePlanActionTest.testNodeAdded-seed#[B1DFD0131B7C99E4])
[n:127.0.0.1:61583_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (0) -> (1)
[junit4] 2> 220653 INFO
(TEST-ComputePlanActionTest.testNodeAdded-seed#[B1DFD0131B7C99E4])
[n:127.0.0.1:61583_solr ] o.a.s.c.Overseer Overseer (id=null) closing
[junit4] 2> 220656 INFO
(TEST-ComputePlanActionTest.testNodeAdded-seed#[B1DFD0131B7C99E4])
[n:127.0.0.1:61583_solr ] o.a.s.c.ZkController Register node as live in
ZooKeeper:/live_nodes/127.0.0.1:61583_solr
[junit4] 2> 220657 DEBUG
(OverseerStateUpdate-98792097810022403-127.0.0.1:61543_solr-n_0000000000)
[n:127.0.0.1:61543_solr ] o.a.s.c.Overseer processMessage: queueSize: 1,
message = {
[junit4] 2> "operation":"downnode",
[junit4] 2> "node_name":"127.0.0.1:61583_solr"} current state version: 0
[junit4] 2> 220657 DEBUG
(OverseerStateUpdate-98792097810022403-127.0.0.1:61543_solr-n_0000000000)
[n:127.0.0.1:61543_solr ] o.a.s.c.o.NodeMutator DownNode state invoked for
node: 127.0.0.1:61583_solr
[junit4] 2> 220658 INFO
(zkCallback-66-thread-2-processing-n:127.0.0.1:61543_solr)
[n:127.0.0.1:61543_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (1) -> (2)
[junit4] 2> 220658 INFO (zkCallback-71-thread-1) [ ]
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
[junit4] 2> 220659 INFO
(zkCallback-92-thread-1-processing-n:127.0.0.1:61583_solr)
[n:127.0.0.1:61583_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (1) -> (2)
[junit4] 2> 220807 INFO
(TEST-ComputePlanActionTest.testNodeAdded-seed#[B1DFD0131B7C99E4])
[n:127.0.0.1:61583_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for
'solr_61583.solr.node' (registry 'solr.node') enabled at server:
com.sun.jmx.mbeanserver.JmxMBeanServer@a7dd5f
[junit4] 2> 220819 INFO
(TEST-ComputePlanActionTest.testNodeAdded-seed#[B1DFD0131B7C99E4])
[n:127.0.0.1:61583_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for
'solr_61583.solr.jvm' (registry 'solr.jvm') enabled at server:
com.sun.jmx.mbeanserver.JmxMBeanServer@a7dd5f
[junit4] 2> 220819 INFO
(TEST-ComputePlanActionTest.testNodeAdded-seed#[B1DFD0131B7C99E4])
[n:127.0.0.1:61583_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for
'solr_61583.solr.jetty' (registry 'solr.jetty') enabled at server:
com.sun.jmx.mbeanserver.JmxMBeanServer@a7dd5f
[junit4] 2> 220821 INFO
(TEST-ComputePlanActionTest.testNodeAdded-seed#[B1DFD0131B7C99E4])
[n:127.0.0.1:61583_solr ] o.a.s.c.CorePropertiesLocator Found 0 core
definitions underneath
C:\Users\jenkins\workspace\Lucene-Solr-master-Windows\solr\build\solr-core\test\J1\temp\solr.cloud.autoscaling.ComputePlanActionTest_B1DFD0131B7C99E4-001\tempDir-001\node2\.
[junit4] 2> 220936 DEBUG (ScheduledTrigger-285-thread-1)
[n:127.0.0.1:61543_solr ] o.a.s.c.a.NodeAddedTrigger Running
NodeAddedTrigger node_added_trigger
[junit4] 2> 220936 DEBUG (ScheduledTrigger-285-thread-1)
[n:127.0.0.1:61543_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes:
[127.0.0.1:61543_solr, 127.0.0.1:61583_solr]
[junit4] 2> 220936 DEBUG (ScheduledTrigger-285-thread-1)
[n:127.0.0.1:61543_solr ] o.a.s.c.a.NodeAddedTrigger Tracking new node:
127.0.0.1:61583_solr at time 1507447786581000000
[junit4] 2> 220940 INFO
(OverseerCollectionConfigSetProcessor-98792097810022403-127.0.0.1:61543_solr-n_0000000000)
[n:127.0.0.1:61543_solr ] o.a.s.c.OverseerTaskQueue Response ZK path:
/overseer/collection-queue-work/qnr-0000000006 doesn't exist. Requestor may
have disconnected from ZooKeeper
[junit4] 2> 221940 DEBUG (ScheduledTrigger-285-thread-1)
[n:127.0.0.1:61543_solr ] o.a.s.c.a.NodeAddedTrigger Running
NodeAddedTrigger node_added_trigger
[junit4] 2> 221940 DEBUG (ScheduledTrigger-285-thread-1)
[n:127.0.0.1:61543_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes:
[127.0.0.1:61543_solr, 127.0.0.1:61583_solr]
[junit4] 2> 221940 DEBUG (ScheduledTrigger-285-thread-1)
[n:127.0.0.1:61543_solr ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger
node_added_trigger firing registered processor for nodes:
[127.0.0.1:61583_solr] added at times [1507447786581000000]
[junit4] 2> 221957 INFO (ScheduledTrigger-285-thread-1)
[n:127.0.0.1:61543_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (0) -> (2)
[junit4] 2> 221960 INFO (ScheduledTrigger-285-thread-1)
[n:127.0.0.1:61543_solr ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster
at 127.0.0.1:61539/solr ready
[junit4] 2> 221962 WARN (NIOServerCxn.Factory:0.0.0.0/0.0.0.0:0) [ ]
o.a.z.s.NIOServerCnxn caught end of stream exception
[junit4] 2> EndOfStreamException: Unable to read additional data from
client sessionid 0x15efae3b895000e, likely client has closed socket
[junit4] 2> at
org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:239)
[junit4] 2> at
org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:203)
[junit4] 2> at java.lang.Thread.run(Thread.java:748)
[junit4] 2> 221962 INFO (ScheduledTrigger-285-thread-1)
[n:127.0.0.1:61543_solr ] o.a.s.c.a.SystemLogListener Collection .system
does not exist, disabling logging.
[junit4] 2> 221968 DEBUG
(AutoscalingActionExecutor-286-thread-1-processing-n:127.0.0.1:61543_solr)
[n:127.0.0.1:61543_solr ] o.a.s.c.a.ScheduledTriggers -- processing actions
for NodeAddedEvent{id='14eb87c66c9bff40T3zjykdlqxg5xtragd2vph09lz',
source='node_added_trigger', eventTime=1507447786581000000,
properties={eventTimes=[1507447786581000000],
_enqueue_time_=1507447787589000000, nodeNames=[127.0.0.1:61583_solr]}}
[junit4] 2> 221975 DEBUG
(AutoscalingActionExecutor-286-thread-1-processing-n:127.0.0.1:61543_solr)
[n:127.0.0.1:61543_solr ] o.a.s.c.a.ComputePlanAction -- processing event:
NodeAddedEvent{id='14eb87c66c9bff40T3zjykdlqxg5xtragd2vph09lz',
source='node_added_trigger', eventTime=1507447786581000000,
properties={eventTimes=[1507447786581000000],
_enqueue_time_=1507447787589000000, nodeNames=[127.0.0.1:61583_solr]}} with
context properties: {BEFORE_ACTION=[compute_plan]}
[junit4] 2> 221985 INFO
(AutoscalingActionExecutor-286-thread-1-processing-n:127.0.0.1:61543_solr)
[n:127.0.0.1:61543_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (0) -> (2)
[junit4] 2> 221988 INFO
(AutoscalingActionExecutor-286-thread-1-processing-n:127.0.0.1:61543_solr)
[n:127.0.0.1:61543_solr ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster
at 127.0.0.1:61539/solr ready
[junit4] 2> 221992 DEBUG
(AutoscalingActionExecutor-286-thread-1-processing-n:127.0.0.1:61543_solr)
[n:127.0.0.1:61543_solr ] o.a.s.c.a.ComputePlanAction Cluster data provider:
{nodeValues={}, liveNodes=[127.0.0.1:61583_solr, 127.0.0.1:61543_solr],
replicaInfo={127.0.0.1:61543_solr={testNodeAdded={shard1=[{core_node3={type=NRT}},
{core_node4={type=NRT}}]}}}}
[junit4] 2> 222061 INFO (qtp11428991-1240) [n:127.0.0.1:61583_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> 222065 INFO (qtp14603425-1171) [n:127.0.0.1:61543_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=2
[junit4] 2> 222069 DEBUG
(AutoscalingActionExecutor-286-thread-1-processing-n:127.0.0.1:61543_solr)
[n:127.0.0.1:61543_solr ] o.a.s.c.a.ComputePlanAction Created suggester with
targetNode: [127.0.0.1:61583_solr]
[junit4] 2> 222069 INFO
(AutoscalingActionExecutor-286-thread-1-processing-n:127.0.0.1:61543_solr)
[n:127.0.0.1:61543_solr ] o.a.s.c.a.ComputePlanAction Computed Plan:
action=MOVEREPLICA&collection=testNodeAdded&targetNode=127.0.0.1:61583_solr&replica=core_node3
[junit4] 2> 222070 DEBUG
(AutoscalingActionExecutor-286-thread-1-processing-n:127.0.0.1:61543_solr)
[n:127.0.0.1:61543_solr ] o.a.s.c.a.ComputePlanAction Created suggester with
targetNode: [127.0.0.1:61583_solr]
[junit4] 2> 222072 INFO
(TEST-ComputePlanActionTest.testNodeAdded-seed#[B1DFD0131B7C99E4]) [ ]
o.a.s.SolrTestCaseJ4 ###Ending testNodeAdded
[junit4] 2> 222090 INFO
(TEST-ComputePlanActionTest.testNodeWithMultipleReplicasLost-seed#[B1DFD0131B7C99E4])
[ ] o.a.s.SolrTestCaseJ4 ###Starting testNodeWithMultipleReplicasLost
[junit4] 2> 222093 DEBUG
(zkCallback-66-thread-2-processing-n:127.0.0.1:61543_solr)
[n:127.0.0.1:61543_solr ] o.a.s.c.a.OverseerTriggerThread Refreshing
/autoscaling.json with znode version 8
[junit4] 2> 222093 DEBUG
(OverseerAutoScalingTriggerThread-98792097810022403-127.0.0.1:61543_solr-n_0000000000)
[n:127.0.0.1:61543_solr ] o.a.s.c.a.OverseerTriggerThread Processed trigger
updates upto znodeVersion 8
[junit4] 2> 222094 INFO
(TEST-ComputePlanActionTest.testNodeWithMultipleReplicasLost-seed#[B1DFD0131B7C99E4])
[ ] o.e.j.s.AbstractConnector Stopped ServerConnector@1c8eca2{SSL,[ssl,
http/1.1]}{127.0.0.1:0}
[junit4] 2> 222094 INFO
(TEST-ComputePlanActionTest.testNodeWithMultipleReplicasLost-seed#[B1DFD0131B7C99E4])
[ ] o.a.s.c.CoreContainer Shutting down CoreContainer instance=1493509
[junit4] 2> 222094 INFO
(TEST-ComputePlanActionTest.testNodeWithMultipleReplicasLost-seed#[B1DFD0131B7C99E4])
[ ] o.a.s.m.SolrMetricManager Closing metric reporters for
registry=solr.node, tag=null
[junit4] 2> 222095 INFO
(TEST-ComputePlanActionTest.testNodeWithMultipleReplicasLost-seed#[B1DFD0131B7C99E4])
[ ] o.a.s.m.r.SolrJmxReporter Closing reporter
[org.apache.solr.metrics.reporters.SolrJmxReporter@3ae9f2: rootName =
solr_61543, domain = solr.node, service url = null, agent id = null] for
registry solr.node / com.codahale.metrics.MetricRegistry@e6602f
[junit4] 2> 222097 DEBUG
(OverseerAutoScalingTriggerThread-98792097810022403-127.0.0.1:61543_solr-n_0000000000)
[n:127.0.0.1:61543_solr ] o.a.s.c.a.OverseerTriggerThread -- clean old
nodeLost markers
[junit4] 2> 222098 DEBUG
(OverseerAutoScalingTriggerThread-98792097810022403-127.0.0.1:61543_solr-n_0000000000)
[n:127.0.0.1:61543_solr ] o.a.s.c.a.OverseerTriggerThread -- clean old
nodeAdded markers
[junit4] 2> 222098 DEBUG
(OverseerAutoScalingTriggerThread-98792097810022403-127.0.0.1:61543_solr-n_0000000000)
[n:127.0.0.1:61543_solr ] o.a.s.c.a.OverseerTriggerThread Current
znodeVersion 8, lastZnodeVersion 8
[junit4] 2> 222106 INFO
(TEST-ComputePlanActionTest.testNodeWithMultipleReplicasLost-seed#[B1DFD0131B7C99E4])
[ ] o.a.s.m.SolrMetricManager Closing metric reporters for
registry=solr.jvm, tag=null
[junit4] 2> 222106 INFO
(TEST-ComputePlanActionTest.testNodeWithMultipleReplicasLost-seed#[B1DFD0131B7C99E4])
[ ] o.a.s.m.r.SolrJmxReporter Closing reporter
[org.apache.solr.metrics.reporters.SolrJmxReporter@3c97d9: rootName =
solr_61543, domain = solr.jvm, service url = null, agent id = null] for
registry solr.jvm / com.codahale.metrics.MetricRegistry@50c979
[junit4] 2> 222111 INFO
(TEST-ComputePlanActionTest.testNodeWithMultipleReplicasLost-seed#[B1DFD0131B7C99E4])
[ ] o.a.s.m.SolrMetricManager Closing metric reporters for
registry=solr.jetty, tag=null
[junit4] 2> 222112 INFO
(TEST-ComputePlanActionTest.testNodeWithMultipleReplicasLost-seed#[B1DFD0131B7C99E4])
[ ] o.a.s.m.r.SolrJmxReporter Closing reporter
[org.apache.solr.metrics.reporters.SolrJmxReporter@85c732: rootName =
solr_61543, domain = solr.jetty, service url = null, agent id = null] for
registry s
[...truncated too long message...]
@50c979
[junit4] 2> 238717 INFO (jetty-closer-60-thread-2) [ ]
o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jetty,
tag=null
[junit4] 2> 238717 INFO (jetty-closer-60-thread-2) [ ]
o.a.s.m.r.SolrJmxReporter Closing reporter
[org.apache.solr.metrics.reporters.SolrJmxReporter@f7de5e: rootName =
solr_61746, domain = solr.jetty, service url = null, agent id = null] for
registry solr.jetty / com.codahale.metrics.MetricRegistry@1fc2aab
[junit4] 2> 238718 INFO (jetty-closer-60-thread-1) [ ]
o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jetty,
tag=null
[junit4] 2> 238718 INFO (jetty-closer-60-thread-1) [ ]
o.a.s.m.r.SolrJmxReporter Closing reporter
[org.apache.solr.metrics.reporters.SolrJmxReporter@19e14c: rootName =
solr_61623, domain = solr.jetty, service url = null, agent id = null] for
registry solr.jetty / com.codahale.metrics.MetricRegistry@1fc2aab
[junit4] 2> 238722 INFO (jetty-closer-60-thread-2) [ ]
o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.cluster,
tag=null
[junit4] 2> 238723 INFO (jetty-closer-60-thread-1) [ ]
o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.cluster,
tag=null
[junit4] 2> 238723 INFO (jetty-closer-60-thread-2) [ ]
o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647
transient cores
[junit4] 2> 238725 WARN
(zkCallback-165-thread-2-processing-n:127.0.0.1:61746_solr)
[n:127.0.0.1:61746_solr ] o.a.s.c.c.ZkStateReader ZooKeeper watch triggered,
but Solr cannot talk to ZK: [KeeperErrorCode = Session expired for /live_nodes]
[junit4] 2> 238726 DEBUG (ScheduledTrigger-365-thread-1)
[n:127.0.0.1:61623_solr ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger:
.auto_add_replicas with currently live nodes: [127.0.0.1:61623_solr,
127.0.0.1:61746_solr]
[junit4] 2> 238726 DEBUG (ScheduledTrigger-365-thread-1)
[n:127.0.0.1:61623_solr ] o.a.s.c.a.NodeLostTrigger Tracking lost node:
127.0.0.1:61694_solr
[junit4] 2> 238727 DEBUG
(OverseerStateUpdate-98792097810022423-127.0.0.1:61623_solr-n_0000000003)
[n:127.0.0.1:61623_solr ] o.a.s.c.Overseer processMessage: queueSize: 2,
message = {
[junit4] 2> "operation":"downnode",
[junit4] 2> "node_name":"127.0.0.1:61746_solr"} current state version: 0
[junit4] 2> 238727 DEBUG
(OverseerStateUpdate-98792097810022423-127.0.0.1:61623_solr-n_0000000003)
[n:127.0.0.1:61623_solr ] o.a.s.c.o.NodeMutator DownNode state invoked for
node: 127.0.0.1:61746_solr
[junit4] 2> 238727 INFO (jetty-closer-60-thread-2) [ ]
o.e.j.s.h.ContextHandler Stopped
o.e.j.s.ServletContextHandler@f84cdc{/solr,null,UNAVAILABLE}
[junit4] 2> 238729 INFO (jetty-closer-60-thread-1) [ ]
o.a.s.c.Overseer Overseer
(id=98792097810022423-127.0.0.1:61623_solr-n_0000000003) closing
[junit4] 2> 238729 INFO
(OverseerStateUpdate-98792097810022423-127.0.0.1:61623_solr-n_0000000003)
[n:127.0.0.1:61623_solr ] o.a.s.c.Overseer Overseer Loop exiting :
127.0.0.1:61623_solr
[junit4] 2> 238732 WARN
(OverseerAutoScalingTriggerThread-98792097810022423-127.0.0.1:61623_solr-n_0000000003)
[n:127.0.0.1:61623_solr ] o.a.s.c.a.OverseerTriggerThread
OverseerTriggerThread woken up but we are closed, exiting.
[junit4] 2> 238732 INFO
(zkCallback-117-thread-2-processing-n:127.0.0.1:61623_solr)
[n:127.0.0.1:61623_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (2) -> (1)
[junit4] 2> 238733 DEBUG (jetty-closer-60-thread-1) [ ]
o.a.s.c.a.OverseerTriggerThread OverseerTriggerThread has been closed explicitly
[junit4] 2> 238735 WARN
(zkCallback-117-thread-2-processing-n:127.0.0.1:61623_solr)
[n:127.0.0.1:61623_solr ] o.a.s.c.c.ZkStateReader ZooKeeper watch triggered,
but Solr cannot talk to ZK: [KeeperErrorCode = Session expired for /live_nodes]
[junit4] 2> 241176 WARN
(zkCallback-117-thread-1-processing-n:127.0.0.1:61623_solr)
[n:127.0.0.1:61623_solr c:testNodeLost s:shard1 r:core_node4
x:testNodeLost_shard1_replica_n2] o.a.s.c.SyncStrategy Closed, skipping sync up.
[junit4] 2> 241176 INFO
(zkCallback-117-thread-1-processing-n:127.0.0.1:61623_solr)
[n:127.0.0.1:61623_solr c:testNodeLost s:shard1 r:core_node4
x:testNodeLost_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> 241176 INFO
(zkCallback-117-thread-1-processing-n:127.0.0.1:61623_solr)
[n:127.0.0.1:61623_solr c:testNodeLost s:shard1 r:core_node4
x:testNodeLost_shard1_replica_n2] o.a.s.c.SolrCore
[testNodeLost_shard1_replica_n2] CLOSING SolrCore
org.apache.solr.core.SolrCore@1254109
[junit4] 2> 241176 INFO
(zkCallback-117-thread-1-processing-n:127.0.0.1:61623_solr)
[n:127.0.0.1:61623_solr c:testNodeLost s:shard1 r:core_node4
x:testNodeLost_shard1_replica_n2] o.a.s.m.SolrMetricManager Closing metric
reporters for registry=solr.core.testNodeLost.shard1.replica_n2, tag=19218697
[junit4] 2> 241176 INFO
(zkCallback-117-thread-1-processing-n:127.0.0.1:61623_solr)
[n:127.0.0.1:61623_solr c:testNodeLost s:shard1 r:core_node4
x:testNodeLost_shard1_replica_n2] o.a.s.m.r.SolrJmxReporter Closing reporter
[org.apache.solr.metrics.reporters.SolrJmxReporter@1ed5ec2: rootName =
solr_61623, domain = solr.core.testNodeLost.shard1.replica_n2, service url =
null, agent id = null] for registry solr.core.testNodeLost.shard1.replica_n2 /
com.codahale.metrics.MetricRegistry@1effe7b
[junit4] 2> 241184 INFO
(zkCallback-117-thread-1-processing-n:127.0.0.1:61623_solr)
[n:127.0.0.1:61623_solr c:testNodeLost s:shard1 r:core_node4
x:testNodeLost_shard1_replica_n2] o.a.s.m.SolrMetricManager Closing metric
reporters for registry=solr.collection.testNodeLost.shard1.leader, tag=19218697
[junit4] 2> 241186 INFO (jetty-closer-60-thread-1) [ ]
o.e.j.s.h.ContextHandler Stopped
o.e.j.s.ServletContextHandler@1481fd{/solr,null,UNAVAILABLE}
[junit4] 2> 241187 ERROR
(SUITE-ComputePlanActionTest-seed#[B1DFD0131B7C99E4]-worker) [ ]
o.a.z.s.ZooKeeperServer ZKShutdownHandler is not registered, so ZooKeeper
server won't take any action on ERROR or SHUTDOWN server state changes
[junit4] 2> 241187 INFO
(SUITE-ComputePlanActionTest-seed#[B1DFD0131B7C99E4]-worker) [ ]
o.a.s.c.ZkTestServer connecting to 127.0.0.1:61539 61539
[junit4] 2> 241189 INFO (Thread-59) [ ] o.a.s.c.ZkTestServer
connecting to 127.0.0.1:61539 61539
[junit4] 2> 241190 WARN (Thread-59) [ ] o.a.s.c.ZkTestServer Watch
limit violations:
[junit4] 2> Maximum concurrent create/delete watches above limit:
[junit4] 2>
[junit4] 2> 25 /solr/aliases.json
[junit4] 2> 7 /solr/security.json
[junit4] 2> 7 /solr/configs/conf
[junit4] 2>
[junit4] 2> Maximum concurrent data watches above limit:
[junit4] 2>
[junit4] 2> 47
/solr/collections/testNodeWithMultipleReplicasLost/state.json
[junit4] 2> 25 /solr/clusterprops.json
[junit4] 2> 25 /solr/clusterstate.json
[junit4] 2> 15 /solr/collections/testNodeLost/state.json
[junit4] 2> 8 /solr/collections/testNodeAdded/state.json
[junit4] 2> 3 /solr/autoscaling.json
[junit4] 2> 3
/solr/overseer_elect/election/98792097810022423-127.0.0.1:61623_solr-n_0000000003
[junit4] 2> 2
/solr/overseer_elect/election/98792097810022413-127.0.0.1:61583_solr-n_0000000001
[junit4] 2> 2
/solr/collections/testNodeWithMultipleReplicasLost/leader_elect/shard1/election/98792097810022423-core_node5-n_0000000000
[junit4] 2> 2
/solr/collections/testNodeWithMultipleReplicasLost/leader_elect/shard2/election/98792097810022413-core_node9-n_0000000000
[junit4] 2>
[junit4] 2> Maximum concurrent children watches above limit:
[junit4] 2>
[junit4] 2> 25 /solr/collections
[junit4] 2> 21 /solr/live_nodes
[junit4] 2> 3 /solr/overseer/queue
[junit4] 2> 3 /solr/autoscaling/events/.auto_add_replicas
[junit4] 2> 3 /solr/overseer/collection-queue-work
[junit4] 2>
[junit4] 2> NOTE: leaving temporary files on disk at:
C:\Users\jenkins\workspace\Lucene-Solr-master-Windows\solr\build\solr-core\test\J1\temp\solr.cloud.autoscaling.ComputePlanActionTest_B1DFD0131B7C99E4-001
[junit4] 2> Oct 08, 2017 7:30:06 AM
com.carrotsearch.randomizedtesting.ThreadLeakControl checkThreadLeaks
[junit4] 2> WARNING: Will linger awaiting termination of 1 leaked
thread(s).
[junit4] 2> NOTE: test params are: codec=Asserting(Lucene70): {},
docValues:{}, maxPointsInLeafNode=491, maxMBSortInHeap=6.600294616233929,
sim=RandomSimilarity(queryNorm=true): {}, locale=ja, timezone=Asia/Katmandu
[junit4] 2> NOTE: Windows 10 10.0 x86/Oracle Corporation 1.8.0_144
(32-bit)/cpus=3,threads=1,free=105983560,total=248512512
[junit4] 2> NOTE: All tests run in this JVM: [TestInPlaceUpdatesDistrib,
AddSchemaFieldsUpdateProcessorFactoryTest,
CloneFieldUpdateProcessorFactoryTest, ComputePlanActionTest]
[junit4] Completed [47/745 (1!)] on J1 in 25.68s, 3 tests, 1 failure <<<
FAILURES!
[...truncated 45030 lines...]
BUILD FAILED
C:\Users\jenkins\workspace\Lucene-Solr-master-Windows\build.xml:826: The
following error occurred while executing this line:
C:\Users\jenkins\workspace\Lucene-Solr-master-Windows\build.xml:706: The
following error occurred while executing this line:
C:\Users\jenkins\workspace\Lucene-Solr-master-Windows\build.xml:693: Source
checkout is dirty (unversioned/missing files) after running tests!!! Offending
files:
* lucene/licenses/morfologik-ukrainian-search-3.7.5.jar.sha1
Total time: 98 minutes 33 seconds
Build step 'Invoke Ant' marked build as failure
Archiving artifacts
[WARNINGS] Skipping publisher since build result is FAILURE
Recording test results
Email was triggered for: Failure - Any
Sending email for trigger: Failure - Any
---------------------------------------------------------------------
To unsubscribe, e-mail: [email protected]
For additional commands, e-mail: [email protected]
