Build: https://jenkins.thetaphi.de/job/Lucene-Solr-master-Linux/21276/
Java: 64bit/jdk-9.0.1 -XX:-UseCompressedOops -XX:+UseSerialGC
1 tests failed.
FAILED:
org.apache.solr.cloud.autoscaling.sim.TestClusterStateProvider.testAutoScalingConfig
Error Message:
expected: org.apache.solr.client.solrj.cloud.autoscaling.AutoScalingConfig<{
"cluster-preferences":[{"maximize":"freedisk"}],
"triggers":{".auto_add_replicas":{ "name":".auto_add_replicas",
"event":"nodeLost", "waitFor":30, "actions":[ {
"name":"auto_add_replicas_plan",
"class":"solr.AutoAddReplicasPlanAction"}, {
"name":"execute_plan", "class":"solr.ExecutePlanAction"}],
"enabled":true}}, "listeners":{".auto_add_replicas.system":{
"trigger":".auto_add_replicas", "afterAction":[], "stage":[
"STARTED", "ABORTED", "SUCCEEDED", "FAILED",
"BEFORE_ACTION", "AFTER_ACTION", "IGNORED"],
"class":"org.apache.solr.cloud.autoscaling.SystemLogListener",
"beforeAction":[]}}, "properties":{}}> but was:
org.apache.solr.client.solrj.cloud.autoscaling.AutoScalingConfig<{
"cluster-preferences":[{"maximize":"freedisk"}],
"triggers":{".auto_add_replicas":{ "name":".auto_add_replicas",
"event":"nodeLost", "waitFor":30, "actions":[ {
"name":"auto_add_replicas_plan",
"class":"solr.AutoAddReplicasPlanAction"}, {
"name":"execute_plan", "class":"solr.ExecutePlanAction"}],
"enabled":true}}, "listeners":{".auto_add_replicas.system":{
"trigger":".auto_add_replicas", "afterAction":[], "stage":[
"STARTED", "ABORTED", "SUCCEEDED", "FAILED",
"BEFORE_ACTION", "AFTER_ACTION", "IGNORED"],
"class":"org.apache.solr.cloud.autoscaling.SystemLogListener",
"beforeAction":[]}}, "properties":{}}>
Stack Trace:
java.lang.AssertionError: expected:
org.apache.solr.client.solrj.cloud.autoscaling.AutoScalingConfig<{
"cluster-preferences":[{"maximize":"freedisk"}],
"triggers":{".auto_add_replicas":{
"name":".auto_add_replicas",
"event":"nodeLost",
"waitFor":30,
"actions":[
{
"name":"auto_add_replicas_plan",
"class":"solr.AutoAddReplicasPlanAction"},
{
"name":"execute_plan",
"class":"solr.ExecutePlanAction"}],
"enabled":true}},
"listeners":{".auto_add_replicas.system":{
"trigger":".auto_add_replicas",
"afterAction":[],
"stage":[
"STARTED",
"ABORTED",
"SUCCEEDED",
"FAILED",
"BEFORE_ACTION",
"AFTER_ACTION",
"IGNORED"],
"class":"org.apache.solr.cloud.autoscaling.SystemLogListener",
"beforeAction":[]}},
"properties":{}}> but was:
org.apache.solr.client.solrj.cloud.autoscaling.AutoScalingConfig<{
"cluster-preferences":[{"maximize":"freedisk"}],
"triggers":{".auto_add_replicas":{
"name":".auto_add_replicas",
"event":"nodeLost",
"waitFor":30,
"actions":[
{
"name":"auto_add_replicas_plan",
"class":"solr.AutoAddReplicasPlanAction"},
{
"name":"execute_plan",
"class":"solr.ExecutePlanAction"}],
"enabled":true}},
"listeners":{".auto_add_replicas.system":{
"trigger":".auto_add_replicas",
"afterAction":[],
"stage":[
"STARTED",
"ABORTED",
"SUCCEEDED",
"FAILED",
"BEFORE_ACTION",
"AFTER_ACTION",
"IGNORED"],
"class":"org.apache.solr.cloud.autoscaling.SystemLogListener",
"beforeAction":[]}},
"properties":{}}>
at
__randomizedtesting.SeedInfo.seed([956EAD68A618714B:AAE6AEC0B14E81AC]:0)
at org.junit.Assert.fail(Assert.java:93)
at org.junit.Assert.failNotEquals(Assert.java:647)
at org.junit.Assert.assertEquals(Assert.java:128)
at org.junit.Assert.assertEquals(Assert.java:147)
at
org.apache.solr.cloud.autoscaling.sim.TestClusterStateProvider.testAutoScalingConfig(TestClusterStateProvider.java:214)
at
java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at
java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at
java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.base/java.lang.reflect.Method.invoke(Method.java:564)
at
com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1737)
at
com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:934)
at
com.carrotsearch.randomizedtesting.RandomizedRunner$9.evaluate(RandomizedRunner.java:970)
at
com.carrotsearch.randomizedtesting.RandomizedRunner$10.evaluate(RandomizedRunner.java:984)
at
com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
at
org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:49)
at
org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
at
org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:48)
at
org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
at
org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
at
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at
com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368)
at
com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:817)
at
com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:468)
at
com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:943)
at
com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:829)
at
com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:879)
at
com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:890)
at
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at
com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
at
org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
at
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at
org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:41)
at
com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
at
com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
at
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at
org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:53)
at
org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
at
org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
at
org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:54)
at
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at
com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368)
at java.base/java.lang.Thread.run(Thread.java:844)
Build Log:
[...truncated 12117 lines...]
[junit4] Suite:
org.apache.solr.cloud.autoscaling.sim.TestClusterStateProvider
[junit4] 2> Creating dataDir:
/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.autoscaling.sim.TestClusterStateProvider_956EAD68A618714B-001/init-core-data-001
[junit4] 2> 481100 INFO
(SUITE-TestClusterStateProvider-seed#[956EAD68A618714B]-worker) [ ]
o.a.s.SolrTestCaseJ4 Using PointFields (NUMERIC_POINTS_SYSPROP=true)
w/NUMERIC_DOCVALUES_SYSPROP=true
[junit4] 2> 481100 INFO
(SUITE-TestClusterStateProvider-seed#[956EAD68A618714B]-worker) [ ]
o.a.s.SolrTestCaseJ4 Randomized ssl (true) and clientAuth (false) via:
@org.apache.solr.util.RandomizeSSL(reason="", ssl=0.0/0.0, value=0.0/0.0,
clientAuth=0.0/0.0)
[junit4] 2> 481101 INFO
(SUITE-TestClusterStateProvider-seed#[956EAD68A618714B]-worker) [ ]
o.a.s.SolrTestCaseJ4 SecureRandom sanity checks:
test.solr.allowed.securerandom=null & java.security.egd=file:/dev/./urandom
[junit4] 2> 481101 INFO
(SUITE-TestClusterStateProvider-seed#[956EAD68A618714B]-worker) [ ]
o.a.s.c.a.s.TestClusterStateProvider ####### Using simulated components? true
[junit4] 2> 481101 INFO
(SUITE-TestClusterStateProvider-seed#[956EAD68A618714B]-worker) [ ]
o.a.s.c.MiniSolrCloudCluster Starting cluster of 3 servers in
/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.autoscaling.sim.TestClusterStateProvider_956EAD68A618714B-001/tempDir-001
[junit4] 2> 481101 INFO
(SUITE-TestClusterStateProvider-seed#[956EAD68A618714B]-worker) [ ]
o.a.s.c.ZkTestServer STARTING ZK TEST SERVER
[junit4] 2> 481101 INFO (Thread-515) [ ] o.a.s.c.ZkTestServer client
port:0.0.0.0/0.0.0.0:0
[junit4] 2> 481101 INFO (Thread-515) [ ] o.a.s.c.ZkTestServer Starting
server
[junit4] 2> 481102 ERROR (Thread-515) [ ] 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> 481201 INFO
(SUITE-TestClusterStateProvider-seed#[956EAD68A618714B]-worker) [ ]
o.a.s.c.ZkTestServer start zk server on port:35371
[junit4] 2> 481203 INFO (zkConnectionManagerCallback-872-thread-1) [ ]
o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 481205 INFO (jetty-launcher-869-thread-2) [ ]
o.e.j.s.Server jetty-9.3.20.v20170531
[junit4] 2> 481205 INFO (jetty-launcher-869-thread-1) [ ]
o.e.j.s.Server jetty-9.3.20.v20170531
[junit4] 2> 481205 INFO (jetty-launcher-869-thread-3) [ ]
o.e.j.s.Server jetty-9.3.20.v20170531
[junit4] 2> 481205 INFO (jetty-launcher-869-thread-1) [ ]
o.e.j.s.h.ContextHandler Started
o.e.j.s.ServletContextHandler@2a2ce3be{/solr,null,AVAILABLE}
[junit4] 2> 481205 INFO (jetty-launcher-869-thread-2) [ ]
o.e.j.s.h.ContextHandler Started
o.e.j.s.ServletContextHandler@26b21342{/solr,null,AVAILABLE}
[junit4] 2> 481206 INFO (jetty-launcher-869-thread-3) [ ]
o.e.j.s.h.ContextHandler Started
o.e.j.s.ServletContextHandler@5b954d4f{/solr,null,AVAILABLE}
[junit4] 2> 481206 INFO (jetty-launcher-869-thread-1) [ ]
o.e.j.s.AbstractConnector Started ServerConnector@127fb04a{SSL,[ssl,
http/1.1]}{127.0.0.1:45667}
[junit4] 2> 481206 INFO (jetty-launcher-869-thread-2) [ ]
o.e.j.s.AbstractConnector Started ServerConnector@779f1db0{SSL,[ssl,
http/1.1]}{127.0.0.1:41443}
[junit4] 2> 481206 INFO (jetty-launcher-869-thread-1) [ ]
o.e.j.s.Server Started @483405ms
[junit4] 2> 481206 INFO (jetty-launcher-869-thread-2) [ ]
o.e.j.s.Server Started @483406ms
[junit4] 2> 481206 INFO (jetty-launcher-869-thread-1) [ ]
o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr,
hostPort=45667}
[junit4] 2> 481206 INFO (jetty-launcher-869-thread-2) [ ]
o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr,
hostPort=41443}
[junit4] 2> 481206 INFO (jetty-launcher-869-thread-3) [ ]
o.e.j.s.AbstractConnector Started ServerConnector@7f0eb71e{SSL,[ssl,
http/1.1]}{127.0.0.1:46393}
[junit4] 2> 481206 INFO (jetty-launcher-869-thread-3) [ ]
o.e.j.s.Server Started @483406ms
[junit4] 2> 481206 INFO (jetty-launcher-869-thread-3) [ ]
o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr,
hostPort=46393}
[junit4] 2> 481207 ERROR (jetty-launcher-869-thread-1) [ ]
o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be
missing or incomplete.
[junit4] 2> 481207 INFO (jetty-launcher-869-thread-1) [ ]
o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version
8.0.0
[junit4] 2> 481207 INFO (jetty-launcher-869-thread-1) [ ]
o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 481207 INFO (jetty-launcher-869-thread-1) [ ]
o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 481207 INFO (jetty-launcher-869-thread-1) [ ]
o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time:
2018-01-15T06:00:44.837243Z
[junit4] 2> 481207 ERROR (jetty-launcher-869-thread-3) [ ]
o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be
missing or incomplete.
[junit4] 2> 481207 INFO (jetty-launcher-869-thread-3) [ ]
o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version
8.0.0
[junit4] 2> 481207 INFO (jetty-launcher-869-thread-3) [ ]
o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 481207 INFO (jetty-launcher-869-thread-3) [ ]
o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 481207 INFO (jetty-launcher-869-thread-3) [ ]
o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time:
2018-01-15T06:00:44.837901Z
[junit4] 2> 481208 INFO (zkConnectionManagerCallback-874-thread-1) [ ]
o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 481208 ERROR (jetty-launcher-869-thread-2) [ ]
o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be
missing or incomplete.
[junit4] 2> 481208 INFO (jetty-launcher-869-thread-2) [ ]
o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version
8.0.0
[junit4] 2> 481208 INFO (jetty-launcher-869-thread-2) [ ]
o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 481208 INFO (jetty-launcher-869-thread-1) [ ]
o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 481208 INFO (jetty-launcher-869-thread-2) [ ]
o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 481208 INFO (jetty-launcher-869-thread-2) [ ]
o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time:
2018-01-15T06:00:44.838585Z
[junit4] 2> 481208 INFO (zkConnectionManagerCallback-876-thread-1) [ ]
o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 481209 INFO (jetty-launcher-869-thread-3) [ ]
o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 481213 INFO (jetty-launcher-869-thread-1) [ ]
o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:35371/solr
[junit4] 2> 481213 INFO (jetty-launcher-869-thread-3) [ ]
o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:35371/solr
[junit4] 2> 481218 INFO (zkConnectionManagerCallback-878-thread-1) [ ]
o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 481218 INFO (zkConnectionManagerCallback-884-thread-1) [ ]
o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 481218 INFO (zkConnectionManagerCallback-886-thread-1) [ ]
o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 481218 INFO (jetty-launcher-869-thread-2) [ ]
o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 481219 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 0x160f867ddbc0005, 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.base/java.lang.Thread.run(Thread.java:844)
[junit4] 2> 481220 INFO
(zkConnectionManagerCallback-889-thread-1-processing-n:127.0.0.1:45667_solr)
[n:127.0.0.1:45667_solr ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 481220 INFO
(zkConnectionManagerCallback-890-thread-1-processing-n:127.0.0.1:46393_solr)
[n:127.0.0.1:46393_solr ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 481235 INFO (jetty-launcher-869-thread-2) [ ]
o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:35371/solr
[junit4] 2> 481236 INFO (zkConnectionManagerCallback-896-thread-1) [ ]
o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 481238 INFO
(zkConnectionManagerCallback-898-thread-1-processing-n:127.0.0.1:41443_solr)
[n:127.0.0.1:41443_solr ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 481243 INFO (jetty-launcher-869-thread-2)
[n:127.0.0.1:41443_solr ] o.a.s.c.Overseer Overseer (id=null) closing
[junit4] 2> 481243 INFO (jetty-launcher-869-thread-2)
[n:127.0.0.1:41443_solr ] o.a.s.c.OverseerElectionContext I am going to be
the leader 127.0.0.1:41443_solr
[junit4] 2> 481244 INFO (jetty-launcher-869-thread-2)
[n:127.0.0.1:41443_solr ] o.a.s.c.Overseer Overseer
(id=99352316787556361-127.0.0.1:41443_solr-n_0000000000) starting
[junit4] 2> 481261 INFO (jetty-launcher-869-thread-3)
[n:127.0.0.1:46393_solr ] o.a.s.c.Overseer Overseer (id=null) closing
[junit4] 2> 481261 INFO (jetty-launcher-869-thread-1)
[n:127.0.0.1:45667_solr ] o.a.s.c.Overseer Overseer (id=null) closing
[junit4] 2> 481261 INFO (jetty-launcher-869-thread-3)
[n:127.0.0.1:46393_solr ] o.a.s.c.ZkController Register node as live in
ZooKeeper:/live_nodes/127.0.0.1:46393_solr
[junit4] 2> 481262 INFO
(OverseerStateUpdate-99352316787556361-127.0.0.1:41443_solr-n_0000000000)
[n:127.0.0.1:41443_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (0) -> (1)
[junit4] 2> 481264 INFO (jetty-launcher-869-thread-1)
[n:127.0.0.1:45667_solr ] o.a.s.c.ZkController Register node as live in
ZooKeeper:/live_nodes/127.0.0.1:45667_solr
[junit4] 2> 481264 INFO (jetty-launcher-869-thread-2)
[n:127.0.0.1:41443_solr ] o.a.s.c.ZkController Register node as live in
ZooKeeper:/live_nodes/127.0.0.1:41443_solr
[junit4] 2> 481279 INFO
(zkCallback-887-thread-1-processing-n:127.0.0.1:46393_solr)
[n:127.0.0.1:46393_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (0) -> (3)
[junit4] 2> 481285 INFO
(zkCallback-897-thread-1-processing-n:127.0.0.1:41443_solr)
[n:127.0.0.1:41443_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (1) -> (3)
[junit4] 2> 481289 INFO
(zkCallback-888-thread-1-processing-n:127.0.0.1:45667_solr)
[n:127.0.0.1:45667_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (0) -> (3)
[junit4] 2> 481308 INFO (jetty-launcher-869-thread-3)
[n:127.0.0.1:46393_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for
'solr_46393.solr.node' (registry 'solr.node') enabled at server:
com.sun.jmx.mbeanserver.JmxMBeanServer@50858ff0
[junit4] 2> 481311 INFO (jetty-launcher-869-thread-1)
[n:127.0.0.1:45667_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for
'solr_45667.solr.node' (registry 'solr.node') enabled at server:
com.sun.jmx.mbeanserver.JmxMBeanServer@50858ff0
[junit4] 2> 481315 INFO (jetty-launcher-869-thread-3)
[n:127.0.0.1:46393_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for
'solr_46393.solr.jvm' (registry 'solr.jvm') enabled at server:
com.sun.jmx.mbeanserver.JmxMBeanServer@50858ff0
[junit4] 2> 481315 INFO (jetty-launcher-869-thread-3)
[n:127.0.0.1:46393_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for
'solr_46393.solr.jetty' (registry 'solr.jetty') enabled at server:
com.sun.jmx.mbeanserver.JmxMBeanServer@50858ff0
[junit4] 2> 481316 INFO (jetty-launcher-869-thread-3)
[n:127.0.0.1:46393_solr ] o.a.s.c.CorePropertiesLocator Found 0 core
definitions underneath
/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.autoscaling.sim.TestClusterStateProvider_956EAD68A618714B-001/tempDir-001/node3/.
[junit4] 2> 481319 INFO (jetty-launcher-869-thread-2)
[n:127.0.0.1:41443_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for
'solr_41443.solr.node' (registry 'solr.node') enabled at server:
com.sun.jmx.mbeanserver.JmxMBeanServer@50858ff0
[junit4] 2> 481319 INFO (jetty-launcher-869-thread-1)
[n:127.0.0.1:45667_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for
'solr_45667.solr.jvm' (registry 'solr.jvm') enabled at server:
com.sun.jmx.mbeanserver.JmxMBeanServer@50858ff0
[junit4] 2> 481320 INFO (jetty-launcher-869-thread-1)
[n:127.0.0.1:45667_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for
'solr_45667.solr.jetty' (registry 'solr.jetty') enabled at server:
com.sun.jmx.mbeanserver.JmxMBeanServer@50858ff0
[junit4] 2> 481321 INFO (jetty-launcher-869-thread-1)
[n:127.0.0.1:45667_solr ] o.a.s.c.CorePropertiesLocator Found 0 core
definitions underneath
/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.autoscaling.sim.TestClusterStateProvider_956EAD68A618714B-001/tempDir-001/node1/.
[junit4] 2> 481326 INFO (jetty-launcher-869-thread-2)
[n:127.0.0.1:41443_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for
'solr_41443.solr.jvm' (registry 'solr.jvm') enabled at server:
com.sun.jmx.mbeanserver.JmxMBeanServer@50858ff0
[junit4] 2> 481326 INFO (jetty-launcher-869-thread-2)
[n:127.0.0.1:41443_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for
'solr_41443.solr.jetty' (registry 'solr.jetty') enabled at server:
com.sun.jmx.mbeanserver.JmxMBeanServer@50858ff0
[junit4] 2> 481327 INFO (jetty-launcher-869-thread-2)
[n:127.0.0.1:41443_solr ] o.a.s.c.CorePropertiesLocator Found 0 core
definitions underneath
/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.autoscaling.sim.TestClusterStateProvider_956EAD68A618714B-001/tempDir-001/node2/.
[junit4] 2> 481407 INFO (zkConnectionManagerCallback-904-thread-1) [ ]
o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 481425 INFO (zkConnectionManagerCallback-908-thread-1) [ ]
o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 481425 INFO
(SUITE-TestClusterStateProvider-seed#[956EAD68A618714B]-worker) [ ]
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (3)
[junit4] 2> 481426 INFO
(SUITE-TestClusterStateProvider-seed#[956EAD68A618714B]-worker) [ ]
o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:35371/solr ready
[junit4] 2> 481441 INFO (qtp1010268621-3071) [n:127.0.0.1:41443_solr ]
o.a.s.h.a.CollectionsHandler Invoked Collection Action :create with params
pullReplicas=1&replicationFactor=2&name=.system&nrtReplicas=2&action=CREATE&numShards=1&tlogReplicas=0&wt=javabin&version=2
and sendToOCPQueue=true
[junit4] 2> 481445 INFO
(OverseerThreadFactory-1361-thread-1-processing-n:127.0.0.1:41443_solr)
[n:127.0.0.1:41443_solr ] o.a.s.c.CreateCollectionCmd Create collection
.system
[junit4] 2> 481550 INFO
(OverseerStateUpdate-99352316787556361-127.0.0.1:41443_solr-n_0000000000)
[n:127.0.0.1:41443_solr ] o.a.s.c.o.SliceMutator createReplica() {
[junit4] 2> "operation":"ADDREPLICA",
[junit4] 2> "collection":".system",
[junit4] 2> "shard":"shard1",
[junit4] 2> "core":".system_shard1_replica_n1",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"https://127.0.0.1:41443/solr";,
[junit4] 2> "type":"NRT",
[junit4] 2> "waitForFinalState":"false"}
[junit4] 2> 481551 INFO
(OverseerStateUpdate-99352316787556361-127.0.0.1:41443_solr-n_0000000000)
[n:127.0.0.1:41443_solr ] o.a.s.c.o.SliceMutator createReplica() {
[junit4] 2> "operation":"ADDREPLICA",
[junit4] 2> "collection":".system",
[junit4] 2> "shard":"shard1",
[junit4] 2> "core":".system_shard1_replica_n2",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"https://127.0.0.1:45667/solr";,
[junit4] 2> "type":"NRT",
[junit4] 2> "waitForFinalState":"false"}
[junit4] 2> 481552 INFO
(OverseerStateUpdate-99352316787556361-127.0.0.1:41443_solr-n_0000000000)
[n:127.0.0.1:41443_solr ] o.a.s.c.o.SliceMutator createReplica() {
[junit4] 2> "operation":"ADDREPLICA",
[junit4] 2> "collection":".system",
[junit4] 2> "shard":"shard1",
[junit4] 2> "core":".system_shard1_replica_p4",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"https://127.0.0.1:46393/solr";,
[junit4] 2> "type":"PULL",
[junit4] 2> "waitForFinalState":"false"}
[junit4] 2> 481761 INFO (qtp1010268621-3063) [n:127.0.0.1:41443_solr ]
o.a.s.h.a.CoreAdminOperation core create command
qt=/admin/cores&coreNodeName=core_node3&collection.configName=.system&newCollection=true&name=.system_shard1_replica_n1&action=CREATE&numShards=1&collection=.system&shard=shard1&wt=javabin&version=2&replicaType=NRT
[junit4] 2> 481761 INFO (qtp1010268621-3063) [n:127.0.0.1:41443_solr ]
o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647
transient cores
[junit4] 2> 481769 INFO (qtp196294282-3086) [n:127.0.0.1:46393_solr ]
o.a.s.h.a.CoreAdminOperation core create command
qt=/admin/cores&coreNodeName=core_node6&collection.configName=.system&newCollection=true&name=.system_shard1_replica_p4&action=CREATE&numShards=1&collection=.system&shard=shard1&wt=javabin&version=2&replicaType=PULL
[junit4] 2> 481769 INFO (qtp196294282-3086) [n:127.0.0.1:46393_solr ]
o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647
transient cores
[junit4] 2> 481772 INFO (qtp175703866-3062) [n:127.0.0.1:45667_solr ]
o.a.s.h.a.CoreAdminOperation core create command
qt=/admin/cores&coreNodeName=core_node5&collection.configName=.system&newCollection=true&name=.system_shard1_replica_n2&action=CREATE&numShards=1&collection=.system&shard=shard1&wt=javabin&version=2&replicaType=NRT
[junit4] 2> 481772 INFO (qtp175703866-3062) [n:127.0.0.1:45667_solr ]
o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647
transient cores
[junit4] 2> 481884 INFO
(zkCallback-888-thread-1-processing-n:127.0.0.1:45667_solr)
[n:127.0.0.1:45667_solr ] o.a.s.c.c.ZkStateReader A cluster state change:
[WatchedEvent state:SyncConnected type:NodeDataChanged
path:/collections/.system/state.json] for collection [.system] has occurred -
updating... (live nodes size: [3])
[junit4] 2> 481884 INFO
(zkCallback-897-thread-1-processing-n:127.0.0.1:41443_solr)
[n:127.0.0.1:41443_solr ] o.a.s.c.c.ZkStateReader A cluster state change:
[WatchedEvent state:SyncConnected type:NodeDataChanged
path:/collections/.system/state.json] for collection [.system] has occurred -
updating... (live nodes size: [3])
[junit4] 2> 481884 INFO
(zkCallback-897-thread-2-processing-n:127.0.0.1:41443_solr)
[n:127.0.0.1:41443_solr ] o.a.s.c.c.ZkStateReader A cluster state change:
[WatchedEvent state:SyncConnected type:NodeDataChanged
path:/collections/.system/state.json] for collection [.system] has occurred -
updating... (live nodes size: [3])
[junit4] 2> 481884 INFO
(zkCallback-887-thread-1-processing-n:127.0.0.1:46393_solr)
[n:127.0.0.1:46393_solr ] o.a.s.c.c.ZkStateReader A cluster state change:
[WatchedEvent state:SyncConnected type:NodeDataChanged
path:/collections/.system/state.json] for collection [.system] has occurred -
updating... (live nodes size: [3])
[junit4] 2> 481884 INFO
(zkCallback-888-thread-2-processing-n:127.0.0.1:45667_solr)
[n:127.0.0.1:45667_solr ] o.a.s.c.c.ZkStateReader A cluster state change:
[WatchedEvent state:SyncConnected type:NodeDataChanged
path:/collections/.system/state.json] for collection [.system] has occurred -
updating... (live nodes size: [3])
[junit4] 2> 481884 INFO
(zkCallback-887-thread-2-processing-n:127.0.0.1:46393_solr)
[n:127.0.0.1:46393_solr ] o.a.s.c.c.ZkStateReader A cluster state change:
[WatchedEvent state:SyncConnected type:NodeDataChanged
path:/collections/.system/state.json] for collection [.system] has occurred -
updating... (live nodes size: [3])
[junit4] 2> 482768 INFO (qtp1010268621-3063) [n:127.0.0.1:41443_solr
c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1] o.a.s.c.SolrConfig
Using Lucene MatchVersion: 8.0.0
[junit4] 2> 482770 INFO (qtp1010268621-3063) [n:127.0.0.1:41443_solr
c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1]
o.a.s.s.ManagedIndexSchemaFactory The schema is configured as managed, but
managed schema resource managed-schema not found - loading non-managed schema
schema.xml instead
[junit4] 2> 482772 INFO (qtp1010268621-3063) [n:127.0.0.1:41443_solr
c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1]
o.a.s.s.IndexSchema [.system_shard1_replica_n1] Schema name=_system collection
or core
[junit4] 2> 482774 INFO (qtp1010268621-3063) [n:127.0.0.1:41443_solr
c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1]
o.a.s.s.IndexSchema Loaded schema _system collection or core/1.1 with uniqueid
field id
[junit4] 2> 482774 INFO (qtp1010268621-3063) [n:127.0.0.1:41443_solr
c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1]
o.a.s.s.ManagedIndexSchema Created and persisted managed schema znode at
/configs/.system/managed-schema
[junit4] 2> 482775 INFO (qtp1010268621-3063) [n:127.0.0.1:41443_solr
c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1]
o.a.s.s.ManagedIndexSchemaFactory After upgrading to managed schema in
ZooKeeper, renamed the non-managed schema /configs/.system/schema.xml to
/configs/.system/schema.xml.bak
[junit4] 2> 482775 INFO (qtp1010268621-3063) [n:127.0.0.1:41443_solr
c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1]
o.a.s.c.CoreContainer Creating SolrCore '.system_shard1_replica_n1' using
configuration from collection .system, trusted=true
[junit4] 2> 482776 INFO (qtp1010268621-3063) [n:127.0.0.1:41443_solr
c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1]
o.a.s.m.r.SolrJmxReporter JMX monitoring for
'solr_41443.solr.core..system.shard1.replica_n1' (registry
'solr.core..system.shard1.replica_n1') enabled at server:
com.sun.jmx.mbeanserver.JmxMBeanServer@50858ff0
[junit4] 2> 482776 INFO (qtp1010268621-3063) [n:127.0.0.1:41443_solr
c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1] o.a.s.c.SolrCore
solr.RecoveryStrategy.Builder
[junit4] 2> 482776 INFO (qtp1010268621-3063) [n:127.0.0.1:41443_solr
c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1] o.a.s.c.SolrCore
[[.system_shard1_replica_n1] ] Opening new SolrCore at
[/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.autoscaling.sim.TestClusterStateProvider_956EAD68A618714B-001/tempDir-001/node2/.system_shard1_replica_n1],
dataDir=[/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.autoscaling.sim.TestClusterStateProvider_956EAD68A618714B-001/tempDir-001/node2/./.system_shard1_replica_n1/data/]
[junit4] 2> 482787 INFO (qtp196294282-3086) [n:127.0.0.1:46393_solr
c:.system s:shard1 r:core_node6 x:.system_shard1_replica_p4] o.a.s.c.SolrConfig
Using Lucene MatchVersion: 8.0.0
[junit4] 2> 482787 INFO (qtp175703866-3062) [n:127.0.0.1:45667_solr
c:.system s:shard1 r:core_node5 x:.system_shard1_replica_n2] o.a.s.c.SolrConfig
Using Lucene MatchVersion: 8.0.0
[junit4] 2> 482806 INFO (qtp196294282-3086) [n:127.0.0.1:46393_solr
c:.system s:shard1 r:core_node6 x:.system_shard1_replica_p4]
o.a.s.s.IndexSchema [.system_shard1_replica_p4] Schema name=_system collection
or core
[junit4] 2> 482806 INFO (qtp175703866-3062) [n:127.0.0.1:45667_solr
c:.system s:shard1 r:core_node5 x:.system_shard1_replica_n2]
o.a.s.s.IndexSchema [.system_shard1_replica_n2] Schema name=_system collection
or core
[junit4] 2> 482809 INFO (qtp196294282-3086) [n:127.0.0.1:46393_solr
c:.system s:shard1 r:core_node6 x:.system_shard1_replica_p4]
o.a.s.s.IndexSchema Loaded schema _system collection or core/1.1 with uniqueid
field id
[junit4] 2> 482809 INFO (qtp175703866-3062) [n:127.0.0.1:45667_solr
c:.system s:shard1 r:core_node5 x:.system_shard1_replica_n2]
o.a.s.s.IndexSchema Loaded schema _system collection or core/1.1 with uniqueid
field id
[junit4] 2> 482809 INFO (qtp196294282-3086) [n:127.0.0.1:46393_solr
c:.system s:shard1 r:core_node6 x:.system_shard1_replica_p4]
o.a.s.c.CoreContainer Creating SolrCore '.system_shard1_replica_p4' using
configuration from collection .system, trusted=true
[junit4] 2> 482809 INFO (qtp175703866-3062) [n:127.0.0.1:45667_solr
c:.system s:shard1 r:core_node5 x:.system_shard1_replica_n2]
o.a.s.c.CoreContainer Creating SolrCore '.system_shard1_replica_n2' using
configuration from collection .system, trusted=true
[junit4] 2> 482810 INFO (qtp196294282-3086) [n:127.0.0.1:46393_solr
c:.system s:shard1 r:core_node6 x:.system_shard1_replica_p4]
o.a.s.m.r.SolrJmxReporter JMX monitoring for
'solr_46393.solr.core..system.shard1.replica_p4' (registry
'solr.core..system.shard1.replica_p4') enabled at server:
com.sun.jmx.mbeanserver.JmxMBeanServer@50858ff0
[junit4] 2> 482810 INFO (qtp175703866-3062) [n:127.0.0.1:45667_solr
c:.system s:shard1 r:core_node5 x:.system_shard1_replica_n2]
o.a.s.m.r.SolrJmxReporter JMX monitoring for
'solr_45667.solr.core..system.shard1.replica_n2' (registry
'solr.core..system.shard1.replica_n2') enabled at server:
com.sun.jmx.mbeanserver.JmxMBeanServer@50858ff0
[junit4] 2> 482810 INFO (qtp196294282-3086) [n:127.0.0.1:46393_solr
c:.system s:shard1 r:core_node6 x:.system_shard1_replica_p4] o.a.s.c.SolrCore
solr.RecoveryStrategy.Builder
[junit4] 2> 482810 INFO (qtp175703866-3062) [n:127.0.0.1:45667_solr
c:.system s:shard1 r:core_node5 x:.system_shard1_replica_n2] o.a.s.c.SolrCore
solr.RecoveryStrategy.Builder
[junit4] 2> 482810 INFO (qtp196294282-3086) [n:127.0.0.1:46393_solr
c:.system s:shard1 r:core_node6 x:.system_shard1_replica_p4] o.a.s.c.SolrCore
[[.system_shard1_replica_p4] ] Opening new SolrCore at
[/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.autoscaling.sim.TestClusterStateProvider_956EAD68A618714B-001/tempDir-001/node3/.system_shard1_replica_p4],
dataDir=[/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.autoscaling.sim.TestClusterStateProvider_956EAD68A618714B-001/tempDir-001/node3/./.system_shard1_replica_p4/data/]
[junit4] 2> 482810 INFO (qtp175703866-3062) [n:127.0.0.1:45667_solr
c:.system s:shard1 r:core_node5 x:.system_shard1_replica_n2] o.a.s.c.SolrCore
[[.system_shard1_replica_n2] ] Opening new SolrCore at
[/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.autoscaling.sim.TestClusterStateProvider_956EAD68A618714B-001/tempDir-001/node1/.system_shard1_replica_n2],
dataDir=[/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.autoscaling.sim.TestClusterStateProvider_956EAD68A618714B-001/tempDir-001/node1/./.system_shard1_replica_n2/data/]
[junit4] 2> 482825 INFO (qtp1010268621-3063) [n:127.0.0.1:41443_solr
c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1]
o.a.s.u.UpdateHandler Using UpdateLog implementation:
org.apache.solr.update.UpdateLog
[junit4] 2> 482825 INFO (qtp1010268621-3063) [n:127.0.0.1:41443_solr
c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1] o.a.s.u.UpdateLog
Initializing UpdateLog: dataDir= defaultSyncLevel=FLUSH numRecordsToKeep=100
maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 482826 INFO (qtp1010268621-3063) [n:127.0.0.1:41443_solr
c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1]
o.a.s.u.CommitTracker Hard AutoCommit: if 1 uncommited docs
[junit4] 2> 482826 INFO (qtp1010268621-3063) [n:127.0.0.1:41443_solr
c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1]
o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 482827 INFO (qtp1010268621-3063) [n:127.0.0.1:41443_solr
c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1]
o.a.s.s.SolrIndexSearcher Opening [Searcher@3cba673c[.system_shard1_replica_n1]
main]
[junit4] 2> 482828 INFO (qtp1010268621-3063) [n:127.0.0.1:41443_solr
c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1]
o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase:
/configs/.system
[junit4] 2> 482828 INFO (qtp1010268621-3063) [n:127.0.0.1:41443_solr
c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1]
o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using
ZooKeeperStorageIO:path=/configs/.system
[junit4] 2> 482828 INFO (qtp1010268621-3063) [n:127.0.0.1:41443_solr
c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1]
o.a.s.s.ZkIndexSchemaReader Creating ZooKeeper watch for the managed schema at
/configs/.system/managed-schema
[junit4] 2> 482828 INFO (qtp1010268621-3063) [n:127.0.0.1:41443_solr
c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1]
o.a.s.s.ZkIndexSchemaReader Current schema version 0 is already the latest
[junit4] 2> 482829 INFO (qtp1010268621-3063) [n:127.0.0.1:41443_solr
c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1]
o.a.s.h.ReplicationHandler Commits will be reserved for 10000ms.
[junit4] 2> 482830 INFO
(searcherExecutor-1368-thread-1-processing-n:127.0.0.1:41443_solr
x:.system_shard1_replica_n1 s:shard1 c:.system r:core_node3)
[n:127.0.0.1:41443_solr c:.system s:shard1 r:core_node3
x:.system_shard1_replica_n1] o.a.s.c.SolrCore [.system_shard1_replica_n1]
Registered new searcher Searcher@3cba673c[.system_shard1_replica_n1]
main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 482830 INFO (qtp1010268621-3063) [n:127.0.0.1:41443_solr
c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1] o.a.s.u.UpdateLog
Could not find max version in index or recent updates, using new clock
1589637070412840960
[junit4] 2> 482833 INFO (qtp1010268621-3063) [n:127.0.0.1:41443_solr
c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1]
o.a.s.c.ShardLeaderElectionContext Waiting until we see more replicas up for
shard shard1: total=2 found=1 timeoutin=9999ms
[junit4] 2> 482873 INFO (qtp196294282-3086) [n:127.0.0.1:46393_solr
c:.system s:shard1 r:core_node6 x:.system_shard1_replica_p4]
o.a.s.u.CommitTracker Hard AutoCommit: if 1 uncommited docs
[junit4] 2> 482873 INFO (qtp196294282-3086) [n:127.0.0.1:46393_solr
c:.system s:shard1 r:core_node6 x:.system_shard1_replica_p4]
o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 482874 INFO (qtp175703866-3062) [n:127.0.0.1:45667_solr
c:.system s:shard1 r:core_node5 x:.system_shard1_replica_n2]
o.a.s.u.UpdateHandler Using UpdateLog implementation:
org.apache.solr.update.UpdateLog
[junit4] 2> 482874 INFO (qtp175703866-3062) [n:127.0.0.1:45667_solr
c:.system s:shard1 r:core_node5 x:.system_shard1_replica_n2] o.a.s.u.UpdateLog
Initializing UpdateLog: dataDir= defaultSyncLevel=FLUSH numRecordsToKeep=100
maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 482875 INFO (qtp175703866-3062) [n:127.0.0.1:45667_solr
c:.system s:shard1 r:core_node5 x:.system_shard1_replica_n2]
o.a.s.u.CommitTracker Hard AutoCommit: if 1 uncommited docs
[junit4] 2> 482875 INFO (qtp175703866-3062) [n:127.0.0.1:45667_solr
c:.system s:shard1 r:core_node5 x:.system_shard1_replica_n2]
o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 482875 INFO (qtp196294282-3086) [n:127.0.0.1:46393_solr
c:.system s:shard1 r:core_node6 x:.system_shard1_replica_p4]
o.a.s.s.SolrIndexSearcher Opening [Searcher@4377ebbc[.system_shard1_replica_p4]
main]
[junit4] 2> 482876 INFO (qtp175703866-3062) [n:127.0.0.1:45667_solr
c:.system s:shard1 r:core_node5 x:.system_shard1_replica_n2]
o.a.s.s.SolrIndexSearcher Opening [Searcher@7b30ab66[.system_shard1_replica_n2]
main]
[junit4] 2> 482876 INFO (qtp196294282-3086) [n:127.0.0.1:46393_solr
c:.system s:shard1 r:core_node6 x:.system_shard1_replica_p4]
o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase:
/configs/.system
[junit4] 2> 482876 INFO (qtp196294282-3086) [n:127.0.0.1:46393_solr
c:.system s:shard1 r:core_node6 x:.system_shard1_replica_p4]
o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using
ZooKeeperStorageIO:path=/configs/.system
[junit4] 2> 482876 INFO (qtp196294282-3086) [n:127.0.0.1:46393_solr
c:.system s:shard1 r:core_node6 x:.system_shard1_replica_p4]
o.a.s.s.ZkIndexSchemaReader Creating ZooKeeper watch for the managed schema at
/configs/.system/managed-schema
[junit4] 2> 482876 INFO (qtp196294282-3086) [n:127.0.0.1:46393_solr
c:.system s:shard1 r:core_node6 x:.system_shard1_replica_p4]
o.a.s.s.ZkIndexSchemaReader Current schema version 0 is already the latest
[junit4] 2> 482876 INFO (qtp175703866-3062) [n:127.0.0.1:45667_solr
c:.system s:shard1 r:core_node5 x:.system_shard1_replica_n2]
o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase:
/configs/.system
[junit4] 2> 482876 INFO (qtp175703866-3062) [n:127.0.0.1:45667_solr
c:.system s:shard1 r:core_node5 x:.system_shard1_replica_n2]
o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using
ZooKeeperStorageIO:path=/configs/.system
[junit4] 2> 482876 INFO (qtp175703866-3062) [n:127.0.0.1:45667_solr
c:.system s:shard1 r:core_node5 x:.system_shard1_replica_n2]
o.a.s.s.ZkIndexSchemaReader Creating ZooKeeper watch for the managed schema at
/configs/.system/managed-schema
[junit4] 2> 482876 INFO (qtp175703866-3062) [n:127.0.0.1:45667_solr
c:.system s:shard1 r:core_node5 x:.system_shard1_replica_n2]
o.a.s.s.ZkIndexSchemaReader Current schema version 0 is already the latest
[junit4] 2> 482877 INFO (qtp196294282-3086) [n:127.0.0.1:46393_solr
c:.system s:shard1 r:core_node6 x:.system_shard1_replica_p4]
o.a.s.h.ReplicationHandler Commits will be reserved for 10000ms.
[junit4] 2> 482877 INFO (qtp175703866-3062) [n:127.0.0.1:45667_solr
c:.system s:shard1 r:core_node5 x:.system_shard1_replica_n2]
o.a.s.h.ReplicationHandler Commits will be reserved for 10000ms.
[junit4] 2> 482877 INFO (qtp175703866-3062) [n:127.0.0.1:45667_solr
c:.system s:shard1 r:core_node5 x:.system_shard1_replica_n2] o.a.s.u.UpdateLog
Could not find max version in index or recent updates, using new clock
1589637070462124032
[junit4] 2> 482877 INFO (qtp196294282-3086) [n:127.0.0.1:46393_solr
c:.system s:shard1 r:core_node6 x:.system_shard1_replica_p4]
o.a.s.c.ZkController .system_shard1_replica_p4 starting background replication
from leader
[junit4] 2> 482877 INFO (qtp196294282-3086) [n:127.0.0.1:46393_solr
c:.system s:shard1 r:core_node6 x:.system_shard1_replica_p4]
o.a.s.c.ReplicateFromLeader Will start replication from leader with poll
interval: 00:00:03
[junit4] 2> 482877 INFO
(searcherExecutor-1370-thread-1-processing-n:127.0.0.1:46393_solr
x:.system_shard1_replica_p4 s:shard1 c:.system r:core_node6)
[n:127.0.0.1:46393_solr c:.system s:shard1 r:core_node6
x:.system_shard1_replica_p4] o.a.s.c.SolrCore [.system_shard1_replica_p4]
Registered new searcher Searcher@4377ebbc[.system_shard1_replica_p4]
main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 482877 INFO
(searcherExecutor-1369-thread-1-processing-n:127.0.0.1:45667_solr
x:.system_shard1_replica_n2 s:shard1 c:.system r:core_node5)
[n:127.0.0.1:45667_solr c:.system s:shard1 r:core_node5
x:.system_shard1_replica_n2] o.a.s.c.SolrCore [.system_shard1_replica_n2]
Registered new searcher Searcher@7b30ab66[.system_shard1_replica_n2]
main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 482878 INFO (qtp196294282-3086) [n:127.0.0.1:46393_solr
c:.system s:shard1 r:core_node6 x:.system_shard1_replica_p4]
o.a.s.h.ReplicationHandler Poll scheduled at an interval of 3000ms
[junit4] 2> 482878 INFO (qtp196294282-3086) [n:127.0.0.1:46393_solr
c:.system s:shard1 r:core_node6 x:.system_shard1_replica_p4]
o.a.s.h.ReplicationHandler Commits will be reserved for 10000ms.
[junit4] 2> 482934 INFO
(zkCallback-887-thread-2-processing-n:127.0.0.1:46393_solr)
[n:127.0.0.1:46393_solr ] o.a.s.c.c.ZkStateReader A cluster state change:
[WatchedEvent state:SyncConnected type:NodeDataChanged
path:/collections/.system/state.json] for collection [.system] has occurred -
updating... (live nodes size: [3])
[junit4] 2> 482934 INFO
(zkCallback-897-thread-2-processing-n:127.0.0.1:41443_solr)
[n:127.0.0.1:41443_solr ] o.a.s.c.c.ZkStateReader A cluster state change:
[WatchedEvent state:SyncConnected type:NodeDataChanged
path:/collections/.system/state.json] for collection [.system] has occurred -
updating... (live nodes size: [3])
[junit4] 2> 482934 INFO
(zkCallback-888-thread-2-processing-n:127.0.0.1:45667_solr)
[n:127.0.0.1:45667_solr ] o.a.s.c.c.ZkStateReader A cluster state change:
[WatchedEvent state:SyncConnected type:NodeDataChanged
path:/collections/.system/state.json] for collection [.system] has occurred -
updating... (live nodes size: [3])
[junit4] 2> 482934 INFO
(zkCallback-888-thread-1-processing-n:127.0.0.1:45667_solr)
[n:127.0.0.1:45667_solr ] o.a.s.c.c.ZkStateReader A cluster state change:
[WatchedEvent state:SyncConnected type:NodeDataChanged
path:/collections/.system/state.json] for collection [.system] has occurred -
updating... (live nodes size: [3])
[junit4] 2> 482934 INFO
(zkCallback-897-thread-3-processing-n:127.0.0.1:41443_solr)
[n:127.0.0.1:41443_solr ] o.a.s.c.c.ZkStateReader A cluster state change:
[WatchedEvent state:SyncConnected type:NodeDataChanged
path:/collections/.system/state.json] for collection [.system] has occurred -
updating... (live nodes size: [3])
[junit4] 2> 482934 INFO
(zkCallback-887-thread-1-processing-n:127.0.0.1:46393_solr)
[n:127.0.0.1:46393_solr ] o.a.s.c.c.ZkStateReader A cluster state change:
[WatchedEvent state:SyncConnected type:NodeDataChanged
path:/collections/.system/state.json] for collection [.system] has occurred -
updating... (live nodes size: [3])
[junit4] 2> 483334 INFO (qtp1010268621-3063) [n:127.0.0.1:41443_solr
c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1]
o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue.
[junit4] 2> 483334 INFO (qtp1010268621-3063) [n:127.0.0.1:41443_solr
c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1]
o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync
[junit4] 2> 483334 INFO (qtp1010268621-3063) [n:127.0.0.1:41443_solr
c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1]
o.a.s.c.SyncStrategy Sync replicas to
https://127.0.0.1:41443/solr/.system_shard1_replica_n1/
[junit4] 2> 483334 INFO (qtp1010268621-3063) [n:127.0.0.1:41443_solr
c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1] o.a.s.u.PeerSync
PeerSync: core=.system_shard1_replica_n1 url=https://127.0.0.1:41443/solr START
replicas=[https://127.0.0.1:45667/solr/.system_shard1_replica_n2/] nUpdates=100
[junit4] 2> 483339 INFO (qtp175703866-3064) [n:127.0.0.1:45667_solr
c:.system s:shard1 r:core_node5 x:.system_shard1_replica_n2] o.a.s.c.S.Request
[.system_shard1_replica_n2] webapp=/solr path=/get
params={distrib=false&qt=/get&fingerprint=false&getVersions=100&wt=javabin&version=2}
status=0 QTime=0
[junit4] 2> 483634 INFO (qtp1010268621-3063) [n:127.0.0.1:41443_solr
c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1] o.a.s.u.PeerSync
PeerSync: core=.system_shard1_replica_n1 url=https://127.0.0.1:41443/solr DONE.
We have no versions. sync failed.
[junit4] 2> 483634 INFO (qtp1010268621-3063) [n:127.0.0.1:41443_solr
c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1]
o.a.s.c.SyncStrategy Leader's attempt to sync with shard failed, moving to the
next candidate
[junit4] 2> 483635 INFO (qtp1010268621-3063) [n:127.0.0.1:41443_solr
c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1]
o.a.s.c.ShardLeaderElectionContext We failed sync, but we have no versions - we
can't sync in that case - we were active before, so become leader anyway
[junit4] 2> 483635 INFO (qtp1010268621-3063) [n:127.0.0.1:41443_solr
c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1]
o.a.s.c.ShardLeaderElectionContext Found all replicas participating in
election, clear LIR
[junit4] 2> 483637 INFO (qtp1010268621-3063) [n:127.0.0.1:41443_solr
c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1]
o.a.s.c.ShardLeaderElectionContext I am the new leader:
https://127.0.0.1:41443/solr/.system_shard1_replica_n1/ shard1
[junit4] 2> 483738 INFO
(zkCallback-888-thread-2-processing-n:127.0.0.1:45667_solr)
[n:127.0.0.1:45667_solr ] o.a.s.c.c.ZkStateReader A cluster state change:
[WatchedEvent state:SyncConnected type:NodeDataChanged
path:/collections/.system/state.json] for collection [.system] has occurred -
updating... (live nodes size: [3])
[junit4] 2> 483738 INFO
(zkCallback-887-thread-1-processing-n:127.0.0.1:46393_solr)
[n:127.0.0.1:46393_solr ] o.a.s.c.c.ZkStateReader A cluster state change:
[WatchedEvent state:SyncConnected type:NodeDataChanged
path:/collections/.system/state.json] for collection [.system] has occurred -
updating... (live nodes size: [3])
[junit4] 2> 483738 INFO
(zkCallback-888-thread-1-processing-n:127.0.0.1:45667_solr)
[n:127.0.0.1:45667_solr ] o.a.s.c.c.ZkStateReader A cluster state change:
[WatchedEvent state:SyncConnected type:NodeDataChanged
path:/collections/.system/state.json] for collection [.system] has occurred -
updating... (live nodes size: [3])
[junit4] 2> 483738 INFO
(zkCallback-897-thread-3-processing-n:127.0.0.1:41443_solr)
[n:127.0.0.1:41443_solr ] o.a.s.c.c.ZkStateReader A cluster state change:
[WatchedEvent state:SyncConnected type:NodeDataChanged
path:/collections/.system/state.json] for collection [.system] has occurred -
updating... (live nodes size: [3])
[junit4] 2> 483738 INFO
(zkCallback-887-thread-2-processing-n:127.0.0.1:46393_solr)
[n:127.0.0.1:46393_solr ] o.a.s.c.c.ZkStateReader A cluster state change:
[WatchedEvent state:SyncConnected type:NodeDataChanged
path:/collections/.system/state.json] for collection [.system] has occurred -
updating... (live nodes size: [3])
[junit4] 2> 483738 INFO
(zkCallback-897-thread-2-processing-n:127.0.0.1:41443_solr)
[n:127.0.0.1:41443_solr ] o.a.s.c.c.ZkStateReader A cluster state change:
[WatchedEvent state:SyncConnected type:NodeDataChanged
path:/collections/.system/state.json] for collection [.system] has occurred -
updating... (live nodes size: [3])
[junit4] 2> 483788 INFO (qtp1010268621-3063) [n:127.0.0.1:41443_solr
c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1]
o.a.s.c.ZkController I am the leader, no recovery necessary
[junit4] 2> 483789 INFO (qtp1010268621-3063) [n:127.0.0.1:41443_solr
c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1]
o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores
params={qt=/admin/cores&coreNodeName=core_node3&collection.configName=.system&newCollection=true&name=.system_shard1_replica_n1&action=CREATE&numShards=1&collection=.system&shard=shard1&wt=javabin&version=2&replicaType=NRT}
status=0 QTime=2028
[junit4] 2> 483880 INFO (qtp196294282-3086) [n:127.0.0.1:46393_solr
c:.system s:shard1 r:core_node6 x:.system_shard1_replica_p4]
o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores
params={qt=/admin/cores&coreNodeName=core_node6&collection.configName=.system&newCollection=true&name=.system_shard1_replica_p4&action=CREATE&numShards=1&collection=.system&shard=shard1&wt=javabin&version=2&replicaType=PULL}
status=0 QTime=2110
[junit4] 2> 483880 INFO (qtp175703866-3062) [n:127.0.0.1:45667_solr
c:.system s:shard1 r:core_node5 x:.system_shard1_replica_n2]
o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores
params={qt=/admin/cores&coreNodeName=core_node5&collection.configName=.system&newCollection=true&name=.system_shard1_replica_n2&action=CREATE&numShards=1&collection=.system&shard=shard1&wt=javabin&version=2&replicaType=NRT}
status=0 QTime=2108
[junit4] 2> 483882 INFO (qtp1010268621-3071) [n:127.0.0.1:41443_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> 483981 INFO
(zkCallback-888-thread-2-processing-n:127.0.0.1:45667_solr)
[n:127.0.0.1:45667_solr ] o.a.s.c.c.ZkStateReader A cluster state change:
[WatchedEvent state:SyncConnected type:NodeDataChanged
path:/collections/.system/state.json] for collection [.system] has occurred -
updating... (live nodes size: [3])
[junit4] 2> 483981 INFO
(zkCallback-887-thread-1-processing-n:127.0.0.1:46393_solr)
[n:127.0.0.1:46393_solr ] o.a.s.c.c.ZkStateReader A cluster state change:
[WatchedEvent state:SyncConnected type:NodeDataChanged
path:/collections/.system/state.json] for collection [.system] has occurred -
updating... (live nodes size: [3])
[junit4] 2> 483981 INFO
(zkCallback-888-thread-1-processing-n:127.0.0.1:45667_solr)
[n:127.0.0.1:45667_solr ] o.a.s.c.c.ZkStateReader A cluster state change:
[WatchedEvent state:SyncConnected type:NodeDataChanged
path:/collections/.system/state.json] for collection [.system] has occurred -
updating... (live nodes size: [3])
[junit4] 2> 483981 INFO
(zkCallback-897-thread-3-processing-n:127.0.0.1:41443_solr)
[n:127.0.0.1:41443_solr ] o.a.s.c.c.ZkStateReader A cluster state change:
[WatchedEvent state:SyncConnected type:NodeDataChanged
path:/collections/.system/state.json] for collection [.system] has occurred -
updating... (live nodes size: [3])
[junit4] 2> 483981 INFO
(zkCallback-887-thread-2-processing-n:127.0.0.1:46393_solr)
[n:127.0.0.1:46393_solr ] o.a.s.c.c.ZkStateReader A cluster state change:
[WatchedEvent state:SyncConnected type:NodeDataChanged
path:/collections/.system/state.json] for collection [.system] has occurred -
updating... (live nodes size: [3])
[junit4] 2> 483981 INFO
(zkCallback-897-thread-2-processing-n:127.0.0.1:41443_solr)
[n:127.0.0.1:41443_solr ] o.a.s.c.c.ZkStateReader A cluster state change:
[WatchedEvent state:SyncConnected type:NodeDataChanged
path:/collections/.system/state.json] for collection [.system] has occurred -
updating... (live nodes size: [3])
[junit4] 2> 484882 INFO (qtp1010268621-3071) [n:127.0.0.1:41443_solr ]
o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections
params={pullReplicas=1&replicationFactor=2&name=.system&nrtReplicas=2&action=CREATE&numShards=1&tlogReplicas=0&wt=javabin&version=2}
status=0 QTime=3440
[junit4] 2> 484888 INFO (qtp1010268621-3063) [n:127.0.0.1:41443_solr ]
o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics
params={prefix=CONTAINER.fs.usableSpace,CORE.coreName&wt=javabin&version=2&group=solr.node,solr.core}
status=0 QTime=0
[junit4] 2> 484892 INFO (qtp175703866-3064) [n:127.0.0.1:45667_solr ]
o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics
params={prefix=CONTAINER.fs.usableSpace,CORE.coreName&wt=javabin&version=2&group=solr.node,solr.core}
status=0 QTime=0
[junit4] 2> 484896 INFO (qtp196294282-3085) [n:127.0.0.1:46393_solr ]
o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics
params={prefix=CONTAINER.fs.usableSpace,CORE.coreName&wt=javabin&version=2&group=solr.node,solr.core}
status=0 QTime=0
[junit4] 2> 484917 INFO
(TEST-TestClusterStateProvider.testAddRemoveNode-seed#[956EAD68A618714B]) [
] o.a.s.SolrTestCaseJ4 ###Starting testAddRemoveNode
[junit4] 2> 484919 INFO
(TEST-TestClusterStateProvider.testAddRemoveNode-seed#[956EAD68A618714B]) [
] o.e.j.s.Server jetty-9.3.20.v20170531
[junit4] 2> 484920 INFO
(TEST-TestClusterStateProvider.testAddRemoveNode-seed#[956EAD68A618714B]) [
] o.e.j.s.h.ContextHandler Started
o.e.j.s.ServletContextHandler@757e1e98{/solr,null,AVAILABLE}
[junit4] 2> 484920 INFO
(TEST-TestClusterStateProvider.testAddRemoveNode-seed#[956EAD68A618714B]) [
] o.e.j.s.AbstractConnector Started ServerConnector@68ec6a00{SSL,[ssl,
http/1.1]}{127.0.0.1:37513}
[junit4] 2> 484921 INFO
(TEST-TestClusterStateProvider.testAddRemoveNode-seed#[956EAD68A618714B]) [
] o.e.j.s.Server Started @487120ms
[junit4] 2> 484921 INFO
(TEST-TestClusterStateProvider.testAddRemoveNode-seed#[956EAD68A618714B]) [
] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr,
hostPort=37513}
[junit4] 2> 484921 ERROR
(TEST-TestClusterStateProvider.testAddRemoveNode-seed#[956EAD68A618714B]) [
] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be
missing or incomplete.
[junit4] 2> 484921 INFO
(TEST-TestClusterStateProvider.testAddRemoveNode-seed#[956EAD68A618714B]) [
] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version
8.0.0
[junit4] 2> 484921 INFO
(TEST-TestClusterStateProvider.testAddRemoveNode-seed#[956EAD68A618714B]) [
] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port
null
[junit4] 2> 484921 INFO
(TEST-TestClusterStateProvider.testAddRemoveNode-seed#[956EAD68A618714B]) [
] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 484921 INFO
(TEST-TestClusterStateProvider.testAddRemoveNode-seed#[956EAD68A618714B]) [
] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time:
2018-01-15T06:00:48.551601Z
[junit4] 2> 484922 INFO (zkConnectionManagerCallback-910-thread-1) [ ]
o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 484923 INFO
(TEST-TestClusterStateProvider.testAddRemoveNode-seed#[956EAD68A618714B]) [
] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 484931 INFO
(TEST-TestClusterStateProvider.testAddRemoveNode-seed#[956EAD68A618714B]) [
] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:35371/solr
[junit4] 2> 484931 INFO (zkConnectionManagerCallback-914-thread-1) [ ]
o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 484933 INFO
(zkConnectionManagerCallback-916-thread-1-processing-n:127.0.0.1:37513_solr)
[n:127.0.0.1:37513_solr ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 484936 INFO
(TEST-TestClusterStateProvider.testAddRemoveNode-seed#[956EAD68A618714B])
[n:127.0.0.1:37513_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (0) -> (3)
[junit4] 2> 484936 INFO
(TEST-TestClusterStateProvider.testAddRemoveNode-seed#[956EAD68A618714B])
[n:127.0.0.1:37513_solr ] o.a.s.c.Overseer Overseer (id=null) closing
[junit4] 2> 484938 INFO
(TEST-TestClusterStateProvider.testAddRemoveNode-seed#[956EAD68A618714B])
[n:127.0.0.1:37513_solr ] o.a.s.c.ZkController Register node as live in
ZooKeeper:/live_nodes/127.0.0.1:37513_solr
[junit4] 2> 484938 INFO (zkCallback-907-thread-1) [ ]
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4)
[junit4] 2> 484939 INFO
(zkCallback-887-thread-2-processing-n:127.0.0.1:46393_solr)
[n:127.0.0.1:46393_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (3) -> (4)
[junit4] 2> 484939 INFO
(zkCallback-888-thread-2-processing-n:127.0.0.1:45667_solr)
[n:127.0.0.1:45667_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (3) -> (4)
[junit4] 2> 484943 INFO
(zkCallback-897-thread-2-processing-n:127.0.0.1:41443_solr)
[n:127.0.0.1:41443_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (3) -> (4)
[junit4] 2> 484943 INFO
(zkCallback-915-thread-1-processing-n:127.0.0.1:37513_solr)
[n:127.0.0.1:37513_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (3) -> (4)
[junit4] 2> 484972 INFO (indexFetcher-1383-thread-1)
[n:127.0.0.1:46393_solr c:.system s:shard1 r:core_node6
x:.system_shard1_replica_p4] o.a.s.h.IndexFetcher Updated masterUrl to
https://127.0.0.1:41443/solr/.system_shard1_replica_n1/
[junit4] 2> 484976 INFO (qtp1010268621-3061) [n:127.0.0.1:41443_solr
c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1] o.a.s.c.S.Request
[.system_shard1_replica_n1] webapp=/solr path=/replication
params={qt=/replication&wt=javabin&version=2&command=indexversion} status=0
QTime=0
[junit4] 2> 484976 INFO (indexFetcher-1383-thread-1)
[n:127.0.0.1:46393_solr c:.system s:shard1 r:core_node6
x:.system_shard1_replica_p4] o.a.s.h.IndexFetcher Master's generation: 1
[junit4] 2> 484976 INFO (indexFetcher-1383-thread-1)
[n:127.0.0.1:46393_solr c:.system s:shard1 r:core_node6
x:.system_shard1_replica_p4] o.a.s.h.IndexFetcher Master's version: 0
[junit4] 2> 484976 INFO (indexFetcher-1383-thread-1)
[n:127.0.0.1:46393_solr c:.system s:shard1 r:core_node6
x:.system_shard1_replica_p4] o.a.s.h.IndexFetcher Slave's generation: 1
[junit4] 2> 484976 INFO (indexFetcher-1383-thread-1)
[n:127.0.0.1:46393_solr c:.system s:shard1 r:core_node6
x:.system_shard1_replica_p4] o.a.s.h.IndexFetcher Slave's version: 0
[junit4] 2> 484976 INFO (indexFetcher-1383-thread-1)
[n:127.0.0.1:46393_solr c:.system s:shard1 r:core_node6
x:.system_shard1_replica_p4] o.a.s.h.IndexFetcher New index in Master. Deleting
mine...
[junit4] 2> 484977 INFO (indexFetcher-1383-thread-1)
[n:127.0.0.1:46393_solr c:.system s:shard1 r:core_node6
x:.system_shard1_replica_p4] o.a.s.u.DirectUpdateHandler2 start
commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 484977 INFO (indexFetcher-1383-thread-1)
[n:127.0.0.1:46393_solr c:.system s:shard1 r:core_node6
x:.system_shard1_replica_p4] o.a.s.u.SolrIndexWriter Calling setCommitData with
IW:org.apache.solr.update.SolrIndexWriter@59ff867f commitCommandVersion:0
[junit4] 2> 484978 INFO (indexFetcher-1383-thread-1)
[n:127.0.0.1:46393_solr c:.system s:shard1 r:core_node6
x:.system_shard1_replica_p4] o.a.s.s.SolrIndexSearcher Opening
[Searcher@cf98296[.system_shard1_replica_p4] main]
[junit4] 2> 484978 INFO (indexFetcher-1383-thread-1)
[n:127.0.0.1:46393_solr c:.system s:shard1 r:core_node6
x:.system_shard1_replica_p4] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 484978 INFO
(searcherExecutor-1370-thread-1-processing-n:127.0.0.1:46393_solr
x:.system_shard1_replica_p4 s:shard1 c:.system r:core_node6)
[n:127.0.0.1:46393_solr c:.system s:shard1 r:core_node6
x:.system_shard1_replica_p4] o.a.s.c.SolrCore [.system_shard1_replica_p4]
Registered new searcher Searcher@cf98296[.system_shard1_replica_p4]
main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 484980 INFO
(TEST-TestClusterStateProvider.testAddRemoveNode-seed#[956EAD68A618714B])
[n:127.0.0.1:37513_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for
'solr_37513.solr.node' (registry 'solr.node') enabled at server:
com.sun.jmx.mbeanserver.JmxMBeanServer@50858ff0
[junit4] 2> 484986 INFO
(TEST-TestClusterStateProvider.testAddRemoveNode-seed#[956EAD68A618714B])
[n:127.0.0.1:37513_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for
'solr_37513.solr.jvm' (registry 'solr.jvm') enabled at server:
com.sun.jmx.mbeanserver.JmxMBeanServer@50858ff0
[junit4] 2> 484986 INFO
(TEST-TestClusterStateProvider.testAddRemoveNode-seed#[956EAD68A618714B])
[n:127.0.0.1:37513_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for
'solr_37513.solr.jetty' (registry 'solr.jetty') enabled at server:
com.sun.jmx.mbeanserver.JmxMBeanServer@50858ff0
[junit4] 2> 484987 INFO
(TEST-TestClusterStateProvider.testAddRemoveNode-seed#[956EAD68A618714B])
[n:127.0.0.1:37513_solr ] o.a.s.c.CorePropertiesLocator Found 0 core
definitions underneath
/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.autoscaling.sim.TestClusterStateProvider_956EAD68A618714B-001/tempDir-001/node4/.
[junit4] 2> 485218 INFO
(TEST-TestClusterStateProvider.testAddRemoveNode-seed#[956EAD68A618714B]) [
] o.e.j.s.AbstractConnector Stopped ServerConnector@127fb04a{SSL,[ssl,
http/1.1]}{127.0.0.1:0}
[junit4] 2> 485219 INFO
(TEST-TestClusterStateProvider.testAddRemoveNode-seed#[956EAD68A618714B]) [
] o.a.s.c.CoreContainer Shutting down CoreContainer instance=1637485926
[junit4] 2> 485219 INFO
(TEST-TestClusterStateProvider.testAddRemoveNode-seed#[956EAD68A618714B]) [
] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.node,
tag=null
[junit4] 2> 485219 INFO
(TEST-TestClusterStateProvider.testAddRemoveNode-seed#[956EAD68A618714B]) [
] o.a.s.m.r.SolrJmxReporter Closing reporter
[org.apache.solr.metrics.reporters.SolrJmxReporter@b72d68d: rootName =
solr_45667, domain = solr.node, service url = null, agent id = null] for
registry solr.node / com.codahale.metrics.MetricRegistry@41946c4
[junit4] 2> 485223 INFO
(TEST-TestClusterStateProvider.testAddRemoveNode-seed#[956EAD68A618714B]) [
] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jvm,
tag=null
[junit4] 2> 485223 INFO
(TEST-TestClusterStateProvider.testAddRemoveNode-seed#[956EAD68A618714B]) [
] o.a.s.m.r.SolrJmxReporter Closing reporter
[org.apache.solr.metrics.reporters.SolrJmxReporter@6c2871b8: rootName =
solr_45667, domain = solr.jvm, service url = null, agent id = null] for
registry solr.jvm / com.codahale.metrics.MetricRegistry@7708928b
[junit4] 2> 485226 INFO
(TEST-TestClusterStateProvider.testAddRemoveNode-seed#[956EAD68A618714B]) [
] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jetty,
tag=null
[junit4] 2> 485226 INFO
(TEST-TestClusterStateProvider.testAddRemoveNode-seed#[956EAD68A618714B]) [
] o.a.s.m.r.SolrJmxReporter Closing reporter
[org.apache.solr.metrics.reporters.SolrJmxReporter@bfe4a84: rootName =
solr_45667, domain = solr.jetty, service url = null, agent id = null] for
registry solr.jetty / com.codahale.metrics.MetricRegistry@453cff07
[junit4] 2> 485227 INFO
(TEST-TestClusterStateProvider.testAddRemoveNode-seed#[956EAD68A618714B]) [
] o.a.s.c.ZkController Remove node as live in
ZooKeeper:/live_nodes/127.0.0.1:45667_solr
[junit4] 2> 485228 INFO
(TEST-TestClusterStateProvider.testAddRemoveNode-seed#[956EAD68A618714B]) [
] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.cluster,
tag=null
[junit4] 2> 485228 INFO (zkCallback-907-thread-1) [ ]
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (4) -> (3)
[junit4] 2> 485228 INFO
(zkCallback-887-thread-2-processing-n:127.0.0.1:46393_solr)
[n:127.0.0.1:46393_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (4) -> (3)
[junit4] 2> 485228 INFO
(zkCallback-888-thread-2-processing-n:127.0.0.1:45667_solr)
[n:127.0.0.1:45667_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (4) -> (3)
[junit4] 2> 485228 INFO
(zkCallback-897-thread-2-processing-n:127.0.0.1:41443_solr)
[n:127.0.0.1:41443_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (4) -> (3)
[junit4] 2> 485228 INFO
(zkCallback-915-thread-1-processing-n:127.0.0.1:37513_solr)
[n:127.0.0.1:37513_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (4) -> (3)
[junit4] 2> 485229 INFO (coreCloseExecutor-1394-thread-1)
[n:127.0.0.1:45667_solr c:.system s:shard1 r:core_node5
x:.system_shard1_replica_n2] o.a.s.c.SolrCore [.system_shard1_replica_n2]
CLOSING SolrCore org.apache.solr.core.SolrCore@255b23da
[junit4] 2> 485229 INFO (coreCloseExecutor-1394-thread-1)
[n:127.0.0.1:45667_solr c:.system s:shard1 r:core_node5
x:.system_shard1_replica_n2] o.a.s.m.SolrMetricManager Closing metric reporters
for registry=solr.core..system.shard1.replica_n2, tag=626729946
[junit4] 2> 485229 INFO (coreCloseExecutor-1394-thread-1)
[n:127.0.0.1:45667_solr c:.system s:shard1 r:core_node5
x:.system_shard1_replica_n2] o.a.s.m.r.SolrJmxReporter Closing reporter
[org.apache.solr.metrics.reporters.SolrJmxReporter@f4e7bf0: rootName =
solr_45667, domain = solr.core..system.shard1.replica_n2, service url = null,
agent id = null] for registry solr.core..system.shard1.replica_n2 /
com.codahale.metrics.MetricRegistry@5c7579a4
[junit4] 2> 485249 INFO (coreCloseExecutor-1394-thread-1)
[n:127.0.0.1:45667_solr c:.system s:shard1 r:core_node5
x:.system_shard1_replica_n2] o.a.s.m.SolrMetricManager Closing metric reporters
for registry=solr.collection..system.shard1.leader, tag=626729946
[junit4] 2> 485250 INFO
(TEST-TestClusterStateProvider.testAddRemoveNode-seed#[956EAD68A618714B]) [
] o.e.j.s.h.ContextHandler Stopped
o.e.j.s.ServletContextHandler@2a2ce3be{/solr,null,UNAVAILABLE}
[junit4] 2> 485329 INFO
(zkCallback-897-thread-3-processing-n:127.0.0.1:41443_solr)
[n:127.0.0.1:41443_solr ] o.a.s.c.c.ZkStateReader A cluster state change:
[WatchedEvent state:SyncConnected type:NodeDataChanged
path:/collections/.system/state.json] for collection [.system] has occurred -
updating... (live nodes size: [3])
[junit4] 2> 485329 INFO
(zkCallback-887-thread-1-processing-n:127.0.0.1:46393_solr)
[n:127.0.0.1:46393_solr ] o.a.s.c.c.ZkStateReader A cluster state change:
[WatchedEvent state:SyncConnected type:NodeDataChanged
path:/collections/.system/state.json] for collection [.system] has occurred -
updating... (live nodes size: [3])
[junit4] 2> 485329 INFO
(zkCallback-897-thread-2-processing-n:127.0.0.1:41443_solr)
[n:127.0.0.1:41443_solr ] o.a.s.c.c.ZkStateReader A cluster state change:
[WatchedEvent state:SyncConnected type:NodeDataChanged
path:/collections/.system/state.json] for collection [.system] has occurred -
updating... (live nodes size: [3])
[junit4] 2> 485329 INFO
(zkCallback-887-thread-2-processing-n:127.0.0.1:46393_solr)
[n:127.0.0.1:46393_solr ] o.a.s.c.c.ZkStateReader A cluster state change:
[WatchedEvent state:SyncConnected type:NodeDataChanged
path:/collections/.system/state.json] for collection [.system] has occurred -
updating... (live nodes size: [3])
[junit4] 2> 485447 INFO
(OverseerCollectionConfigSetProcessor-99352316787556361-127.0.0.1:41443_solr-n_0000000000)
[n:127.0.0.1:41443_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> 485452 INFO
(TEST-TestClusterStateProvider.testAddRemoveNode-seed#[956EAD68A618714B]) [
] o.a.s.SolrTestCaseJ4 ###Ending testAddRemoveNode
[junit4] 2> 485461 INFO
(TEST-TestClusterStateProvider.testAutoScalingConfig-seed#[956EAD68A618714B]) [
] o.a.s.SolrTestCaseJ4 ###Starting testAutoScalingConfig
[junit4] 2> 485463 INFO
(TEST-TestClusterStateProvider.testAutoScalingConfig-seed#[956EAD68A618714B]) [
] o.a.s.SolrTestCaseJ4 ###Ending testAutoScalingConfig
[junit4] 2> NOTE: reproduce with: ant test
-Dtestcase=TestClusterStateProvider -Dtests.method=testAutoScalingConfig
-Dtests.seed=956EAD68A618714B -Dtests.multiplier=3 -Dtests.slow=true
-Dtests.locale=fr-PF -Dtests.timezone=Etc/GMT-6 -Dtests.asserts=true
-Dtests.file.encoding=ISO-8859-1
[junit4] FAILURE 0.01s J2 | TestClusterStateProvider.testAutoScalingConfig
<<<
[junit4] > Throwable #1: java.lang.AssertionError: expected:
org.apache.solr.client.solrj.cloud.autoscaling.AutoScalingConfig<{
[junit4] > "cluster-preferences":[{"maximize":"freedisk"}],
[junit4] > "triggers":{".auto_add_replicas":{
[junit4] > "name":".auto_add_replicas",
[junit4] > "event":"nodeLost",
[junit4] > "waitFor":30,
[junit4] > "actions":[
[junit4] > {
[junit4] > "name":"auto_add_replicas_plan",
[junit4] > "class":"solr.AutoAddReplicasPlanAction"},
[junit4] > {
[junit4] > "name":"execute_plan",
[junit4] > "class":"solr.ExecutePlanAction"}],
[junit4] > "enabled":true}},
[junit4] > "listeners":{".auto_add_replicas.system":{
[junit4] > "trigger":".auto_add_replicas",
[junit4] > "afterAction":[],
[junit4] > "stage":[
[junit4] > "STARTED",
[junit4] > "ABORTED",
[junit4] > "SUCCEEDED",
[junit4] > "FAILED",
[junit4] > "BEFORE_ACTION",
[junit4] > "AFTER_ACTION",
[junit4] > "IGNORED"],
[junit4] >
"class":"org.apache.solr.cloud.autoscaling.SystemLogListener",
[junit4] > "beforeAction":[]}},
[junit4] > "properties":{}}> but was:
org.apache.solr.client.solrj.cloud.autoscaling.AutoScalingConfig<{
[junit4] > "cluster-preferences":[{"maximize":"freedisk"}],
[junit4] > "triggers":{".auto_add_replicas":{
[junit4] > "name":".auto_add_replicas",
[junit4] > "event":"nodeLost",
[junit4] > "waitFor":30,
[junit4] > "actions":[
[junit4] > {
[junit4] > "name":"auto_add_replicas_plan",
[junit4] > "class":"solr.AutoAddReplicasPlanAction"},
[junit4] > {
[junit4] > "name":"execute_plan",
[junit4] > "class":"solr.ExecutePlanAction"}],
[junit4] > "enabled":true}},
[junit4] > "listeners":{".auto_add_replicas.system":{
[junit4] > "trigger":".auto_add_replicas",
[junit4] > "afterAction":[],
[junit4] > "stage":[
[junit4] > "STARTED",
[junit4] > "ABORTED",
[junit4] > "SUCCEEDED",
[junit4] > "FAILED",
[junit4] > "BEFORE_ACTION",
[junit4] > "AFTER_ACTION",
[junit4] > "IGNORED"],
[junit4] >
"class":"org.apache.solr.cloud.autoscaling.SystemLogListener",
[junit4] > "beforeAction":[]}},
[junit4] > "properties":{}}>
[junit4] > at
__randomizedtesting.SeedInfo.seed([956EAD68A618714B:AAE6AEC0B14E81AC]:0)
[junit4] > at
org.apache.solr.cloud.autoscaling.sim.TestClusterStateProvider.testAutoScalingConfig(TestClusterStateProvider.java:214)
[junit4] > at
java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
[junit4] > at
java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
[junit4] > at
java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
[junit4] > at
java.base/java.lang.reflect.Method.invoke(Method.java:564)
[junit4] > at java.base/java.lang.Thread.run(Thread.java:844)
[junit4] 2> 485465 WARN (Simulated OverseerAutoScalingTriggerThread) [
] o.a.s.c.a.OverseerTriggerThread OverseerTriggerThread woken up but we are
closed, exiting.
[junit4] 2> 485469 INFO (jetty-closer-870-thread-3) [ ]
o.e.j.s.AbstractConnector Stopped ServerConnector@68ec6a00{SSL,[ssl,
http/1.1]}{127.0.0.1:0}
[junit4] 2> 485469 INFO (jetty-closer-870-thread-3) [ ]
o.a.s.c.CoreContainer Shutting down CoreContainer instance=1049876059
[junit4] 2> 485469 INFO (jetty-closer-870-thread-3) [ ]
o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.node,
tag=null
[junit4] 2> 485469 INFO (jetty-closer-870-thread-1) [ ]
o.e.j.s.AbstractConnector Stopped ServerConnector@7f0eb71e{SSL,[ssl,
http/1.1]}{127.0.0.1:0}
[junit4] 2> 485469 INFO (jetty-closer-870-thread-3) [ ]
o.a.s.m.r.SolrJmxReporter Closing reporter
[org.apache.solr.metrics.reporters.SolrJmxReporter@3a45b0d5: rootName =
solr_37513, domain = solr.node, service url = null, agent id = null] for
registry solr.node / com.codahale.metrics.MetricRegistry@1655e76a
[junit4] 2> 485469 INFO (jetty-closer-870-thread-1) [ ]
o.a.s.c.CoreContainer Shutting down CoreContainer instance=2029198474
[junit4] 2> 485469 INFO (jetty-closer-870-thread-2) [ ]
o.e.j.s.AbstractConnector Stopped ServerConnector@779f1db0{SSL,[ssl,
http/1.1]}{127.0.0.1:0}
[junit4] 2> 485469 INFO (jetty-closer-870-thread-2) [ ]
o.a.s.c.CoreContainer Shutting down CoreContainer instance=987651807
[junit4] 2> 485469 INFO (jetty-closer-870-thread-2) [ ]
o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.node,
tag=null
[junit4] 2> 485469 INFO (jetty-closer-870-thread-2) [ ]
o.a.s.m.r.SolrJmxReporter Closing reporter
[org.apache.solr.metrics.reporters.SolrJmxReporter@7764375b: rootName =
solr_41443, domain = solr.node, service url = null, agent id = null] for
registry solr.node / com.codahale.metrics.MetricRegistry@3ebb251f
[junit4] 2> 485470 INFO (jetty-closer-870-thread-1) [ ]
o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.node,
tag=null
[junit4] 2> 485470 INFO (jetty-closer-870-thread-1) [ ]
o.a.s.m.r.SolrJmxReporter Closing reporter
[org.apache.solr.metrics.reporters.SolrJmxReporter@7c4442d9: rootName =
solr_46393, domain = solr.node, service url = null, agent id = null] for
registry solr.node / com.codahale.metrics.MetricRegistry@18f54a1a
[junit4] 2> 485473 INFO (jetty-closer-870-thread-2) [ ]
o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jvm,
tag=null
[junit4] 2> 485473 INFO (jetty-closer-870-thread-2) [ ]
o.a.s.m.r.SolrJmxReporter Closing reporter
[org.apache.solr.metrics.reporters.SolrJmxReporter@20100709: rootName =
solr_41443, domain = solr.jvm, service url = null, agent id = null] for
registry solr.jvm / com.codahale.metrics.MetricRegistry@7708928b
[junit4] 2> 485474 INFO (jetty-closer-870-thread-1) [ ]
o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jvm,
tag=null
[junit4] 2> 485474 INFO (jetty-closer-870-thread-1) [ ]
o.a.s.m.r.SolrJmxReporter Closing reporter
[org.apache.solr.metrics.reporters.SolrJmxReporter@fc95baf: rootName =
solr_46393, domain = solr.jvm, service url = null, agent id = null] for
registry solr.jvm / com.codahale.metrics.MetricRegistry@7708928b
[junit4] 2> 485475 INFO (jetty-closer-870-thread-3) [ ]
o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jvm,
tag=null
[junit4] 2> 485475 INFO (jetty-closer-870-thread-3) [ ]
o.a.s.m.r.SolrJmxReporter Closing reporter
[org.apache.solr.metrics.reporters.SolrJmxReporter@20edafc6: rootName =
solr_37513, domain = solr.jvm, service url = null, agent id = null] for
registry solr.jvm / com.codahale.metrics.MetricRegistry@7708928b
[junit4] 2> 485476 INFO (jetty-closer-870-thread-2) [ ]
o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jetty,
tag=null
[junit4] 2> 485476 INFO (jetty-closer-870-thread-2) [ ]
o.a.s.m.r.SolrJmxReporter Closing reporter
[org.apache.solr.metrics.reporters.SolrJmxReporter@7ef0384c: rootName =
solr_41443, domain = solr.jetty, service url = null, agent id = null] for
registry solr.jetty / com.codahale.metrics.MetricRegistry@453cff07
[junit4] 2> 485476 INFO (jetty-closer-870-thread-2) [ ]
o.a.s.c.ZkController Remove node as live in
ZooKeeper:/live_nodes/127.0.0.1:41443_solr
[junit4] 2> 485477 INFO (jetty-closer-870-thread-1) [ ]
o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jetty,
tag=null
[junit4] 2> 485477 INFO (jetty-closer-870-thread-2) [ ]
o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.cluster,
tag=null
[junit4] 2> 485477 INFO (jetty-closer-870-thread-1) [ ]
o.a.s.m.r.SolrJmxReporter Closing reporter
[org.apache.solr.metrics.reporters.SolrJmxReporter@5a7d18b2: rootName =
solr_46393, domain = solr.jetty, service url = null, agent id = null] for
registry solr.jetty / com.codahale.metrics.MetricRegistry@453cff07
[junit4] 2> 485477 INFO
(zkCallback-915-thread-1-processing-n:127.0.0.1:37513_solr)
[n:127.0.0.1:37513_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (3) -> (2)
[junit4] 2> 485477 INFO
(zkCallback-897-thread-2-processing-n:127.0.0.1:41443_solr)
[n:127.0.0.1:41443_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (3) -> (2)
[junit4] 2> 485477 INFO
(zkCallback-887-thread-2-processing-n:127.0.0.1:46393_solr)
[n:127.0.0.1:46393_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (3) -> (2)
[junit4] 2> 485477 INFO (coreCloseExecutor-1396-thread-1)
[n:127.0.0.1:41443_solr c:.system s:shard1 r:core_node3
x:.system_shard1_replica_n1] o.a.s.c.SolrCore [.system_shard1_replica_n1]
CLOSING SolrCore org.apache.solr.core.SolrCore@1577be7e
[junit4] 2> 485477 INFO (coreCloseExecutor-1396-thread-1)
[n:127.0.0.1:41443_solr c:.system s:shard1 r:core_node3
x:.system_shard1_replica_n1] o.a.s.m.SolrMetricManager Closing metric reporters
for registry=solr.core..system.shard1.replica_n1, tag=360169086
[junit4] 2> 485477 INFO (coreCloseExecutor-1396-thread-1)
[n:127.0.0.1:41443_solr c:.system s:shard1 r:core_node3
x:.system_shard1_replica_n1] o.a.s.m.r.SolrJmxReporter Closing reporter
[org.apache.solr.metrics.reporters.SolrJmxReporter@6ebb85a8: rootName =
solr_41443, domain = solr.core..system.shard1.replica_n1, service url = null,
agent id = null] for registry solr.core..system.shard1.replica_n1 /
com.codahale.metrics.MetricRegistry@7327fcc3
[junit4] 2> 485478 INFO (jetty-closer-870-thread-1) [ ]
o.a.s.c.ZkController Remove node as live in
ZooKeeper:/live_nodes/127.0.0.1:46393_solr
[junit4] 2> 485478 INFO
(zkCallback-915-thread-1-processing-n:127.0.0.1:37513_solr)
[n:127.0.0.1:37513_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (2) -> (1)
[junit4] 2> 485478 INFO
(zkCallback-897-thread-2-processing-n:127.0.0.1:41443_solr)
[n:127.0.0.1:41443_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (2) -> (1)
[junit4] 2> 485478 INFO (jetty-closer-870-thread-1) [ ]
o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.cluster,
tag=null
[junit4] 2> 485478 INFO
(zkCallback-887-thread-2-processing-n:127.0.0.1:46393_solr)
[n:127.0.0.1:46393_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (2) -> (1)
[junit4] 2> 485479 INFO (coreCloseExecutor-1397-thread-1)
[n:127.0.0.1:46393_solr c:.system s:shard1 r:core_node6
x:.system_shard1_replica_p4] o.a.s.c.SolrCore [.system_shard1_replica_p4]
CLOSING SolrCore org.apache.solr.core.SolrCore@4a6cb6d9
[junit4] 2> 485479 INFO (coreCloseExecutor-1397-thread-1)
[n:127.0.0.1:46393_solr c:.system s:shard1 r:core_node6
x:.system_shard1_replica_p4] o.a.s.m.SolrMetricManager Closing metric reporters
for registry=solr.core..system.shard1.replica_p4, tag=1248638681
[junit4] 2> 485479 INFO (coreCloseExecutor-1397-thread-1)
[n:127.0.0.1:46393_solr c:.system s:shard1 r:core_node6
x:.system_shard1_replica_p4] o.a.s.m.r.SolrJmxReporter Closing reporter
[org.apache.solr.metrics.reporters.SolrJmxReporter@fc030b0: rootName =
solr_46393, domain = solr.core..system.shard1.replica_p4, service url = null,
agent id = null] for registry solr.core..system.shard1.replica_p4 /
com.codahale.metrics.MetricRegistry@1b333cd6
[junit4] 2> 485480 INFO (jetty-closer-870-thread-3) [ ]
o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jetty,
tag=null
[junit4] 2> 485480 INFO (jetty-closer-870-thread-3) [ ]
o.a.s.m.r.SolrJmxReporter Closing reporter
[org.apache.solr.metrics.reporters.SolrJmxReporter@242bf00e: rootName =
solr_37513, domain = solr.jetty, service url = null, agent id = null] for
registry solr.jetty / com.codahale.metrics.MetricRegistry@453cff07
[junit4] 2> 485480 INFO (jetty-closer-870-thread-3) [ ]
o.a.s.c.ZkController Remove node as live in
ZooKeeper:/live_nodes/127.0.0.1:37513_solr
[junit4] 2> 485481 INFO (jetty-closer-870-thread-3) [ ]
o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.cluster,
tag=null
[junit4] 2> 485481 INFO
(zkCallback-897-thread-2-processing-n:127.0.0.1:41443_solr)
[n:127.0.0.1:41443_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (1) -> (0)
[junit4] 2> 485481 INFO
(zkCallback-915-thread-1-processing-n:127.0.0.1:37513_solr)
[n:127.0.0.1:37513_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (1) -> (0)
[junit4] 2> 485481 INFO (jetty-closer-870-thread-3) [ ]
o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647
transient cores
[junit4] 2> 485482 INFO (jetty-closer-870-thread-3) [ ]
o.e.j.s.h.ContextHandler Stopped
o.e.j.s.ServletContextHandler@757e1e98{/solr,null,UNAVAILABLE}
[junit4] 2> 485486 INFO (coreCloseExecutor-1396-thread-1)
[n:127.0.0.1:41443_solr c:.system s:shard1 r:core_node3
x:.system_shard1_replica_n1] o.a.s.m.SolrMetricManager Closing metric reporters
for registry=solr.collection..system.shard1.leader, tag=360169086
[junit4] 2> 485487 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 0x160f867ddbc000e, 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.base/java.lang.Thread.run(Thread.java:844)
[junit4] 2> 485488 INFO (coreCloseExecutor-1397-thread-1)
[n:127.0.0.1:46393_solr c:.system s:shard1 r:core_node6
x:.system_shard1_replica_p4] o.a.s.m.SolrMetricManager Closing metric reporters
for registry=solr.collection..system.shard1.leader, tag=1248638681
[junit4] 2> 485488 INFO
(zkCallback-887-thread-2-processing-n:127.0.0.1:46393_solr)
[n:127.0.0.1:46393_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (1) -> (0)
[junit4] 2> 485492 INFO (jetty-closer-870-thread-2) [ ]
o.a.s.c.Overseer Overseer
(id=99352316787556361-127.0.0.1:41443_solr-n_0000000000) closing
[junit4] 2> 485492 INFO
(OverseerStateUpdate-99352316787556361-127.0.0.1:41443_solr-n_0000000000)
[n:127.0.0.1:41443_solr ] o.a.s.c.Overseer Overseer Loop exiting :
127.0.0.1:41443_solr
[junit4] 2> 485492 WARN
(OverseerAutoScalingTriggerThread-99352316787556361-127.0.0.1:41443_solr-n_0000000000)
[n:127.0.0.1:41443_solr ] o.a.s.c.a.OverseerTriggerThread
OverseerTriggerThread woken up but we are closed, exiting.
[junit4] 2> 485494 INFO (jetty-closer-870-thread-1) [ ]
o.e.j.s.h.ContextHandler Stopped
o.e.j.s.ServletContextHandler@5b954d4f{/solr,null,UNAVAILABLE}
[junit4] 2> 485495 INFO (jetty-closer-870-thread-2) [ ]
o.e.j.s.h.ContextHandler Stopped
o.e.j.s.ServletContextHandler@26b21342{/solr,null,UNAVAILABLE}
[junit4] 2> 485496 ERROR
(SUITE-TestClusterStateProvider-seed#[956EAD68A618714B]-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> 485496 INFO
(SUITE-TestClusterStateProvider-seed#[956EAD68A618714B]-worker) [ ]
o.a.s.c.ZkTestServer connecting to 127.0.0.1:35371 35371
[junit4] 2> 491278 INFO (Thread-515) [ ] o.a.s.c.ZkTestServer
connecting to 127.0.0.1:35371 35371
[junit4] 2> 491279 WARN (Thread-515) [ ] o.a.s.c.ZkTestServer Watch
limit violations:
[junit4] 2> Maximum concurrent create/delete watches above limit:
[junit4] 2>
[junit4] 2> 5 /solr/aliases.json
[junit4] 2> 4 /solr/security.json
[junit4] 2> 3 /solr/configs/.system
[junit4] 2> 3 /solr/configs/.system/managed-schema
[junit4] 2>
[junit4] 2> Maximum concurrent data watches above limit:
[junit4] 2>
[junit4] 2> 20 /solr/collections/.system/state.json
[junit4] 2> 5 /solr/clusterstate.json
[junit4] 2> 5 /solr/clusterprops.json
[junit4] 2> 2
/solr/overseer_elect/election/99352316787556359-127.0.0.1:46393_solr-n_0000000001
[junit4] 2>
[junit4] 2> Maximum concurrent children watches above limit:
[junit4] 2>
[junit4] 2> 5 /solr/live_nodes
[junit4] 2> 5 /solr/collections
[junit4] 2>
[junit4] 2> NOTE: leaving temporary files on disk at:
/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.autoscaling.sim.TestClusterStateProvider_956EAD68A618714B-001
[junit4] 2> NOTE: test params are: codec=Asserting(Lucene70),
sim=Asserting(org.apache.lucene.search.similarities.AssertingSimilarity@31c3e760),
locale=fr-PF, timezone=Etc/GMT-6
[junit4] 2> NOTE: Linux 4.13.0-26-generic amd64/Oracle Corporation 9.0.1
(64-bit)/cpus=8,threads=1,free=136544664,total=518979584
[junit4] 2> NOTE: All tests run in this JVM:
[TestSerializedLuceneMatchVersion, TestNumericTerms64,
UniqFieldsUpdateProcessorFactoryTest, IndexBasedSpellCheckerTest,
TestTolerantSearch, ZkFailoverTest, TestCSVResponseWriter,
CdcrBidirectionalTest, UnloadDistributedZkTest, TestExpandComponent,
SystemLogListenerTest, TestCharFilters, TestInfoStreamLogging,
TestExceedMaxTermLength, PeerSyncWithIndexFingerprintCachingTest,
ConfigureRecoveryStrategyTest, TestCoreDiscovery,
LeaderFailureAfterFreshStartTest, LeaderElectionTest,
SpellPossibilityIteratorTest, TestValueSourceCache, TestCoreContainer,
SolrGraphiteReporterTest, BigEndianAscendingWordSerializerTest,
TestExtendedDismaxParser, TimeZoneUtilsTest, SolrTestCaseJ4Test,
RequiredFieldsTest, TestApiFramework, TestQueryTypes, ReturnFieldsTest,
TestCloudNestedDocsSort, TestSolrCloudWithKerberosAlt, SolrCLIZkUtilsTest,
ConnectionReuseTest, BadComponentTest, TestManagedSchemaThreadSafety,
CopyFieldTest, TestCollapseQParserPlugin, NodeAddedTriggerTest, UtilsToolTest,
TestGeoJSONResponseWriter, NumberUtilsTest, TestHashPartitioner,
TestLegacyFieldReuse, XmlUpdateRequestHandlerTest, BlobRepositoryCloudTest,
TestPKIAuthenticationPlugin, TestClusterStateProvider]
[junit4] Completed [145/768 (1!)] on J2 in 10.19s, 2 tests, 1 failure <<<
FAILURES!
[...truncated 42948 lines...]
---------------------------------------------------------------------
To unsubscribe, e-mail: [email protected]
For additional commands, e-mail: [email protected]
