You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@lucene.apache.org by Policeman Jenkins Server <je...@thetaphi.de> on 2018/08/11 21:02:01 UTC
[JENKINS] Lucene-Solr-7.x-Linux (64bit/jdk-10.0.1) - Build # 2536 -
Unstable!
Build: https://jenkins.thetaphi.de/job/Lucene-Solr-7.x-Linux/2536/
Java: 64bit/jdk-10.0.1 -XX:-UseCompressedOops -XX:+UseParallelGC
1 tests failed.
FAILED: org.apache.solr.cloud.api.collections.CollectionsAPIDistributedZkTest.testCollectionsAPI
Error Message:
Error from server at http://127.0.0.1:36605/solr/awhollynewcollection_0_shard2_replica_n6: ClusterState says we are the leader (http://127.0.0.1:36605/solr/awhollynewcollection_0_shard2_replica_n6), but locally we don't think so. Request came from null
Stack Trace:
org.apache.solr.client.solrj.impl.CloudSolrClient$RouteException: Error from server at http://127.0.0.1:36605/solr/awhollynewcollection_0_shard2_replica_n6: ClusterState says we are the leader (http://127.0.0.1:36605/solr/awhollynewcollection_0_shard2_replica_n6), but locally we don't think so. Request came from null
at __randomizedtesting.SeedInfo.seed([97ECC742B916BBB3:DF99B3F6BF259426]:0)
at org.apache.solr.client.solrj.impl.CloudSolrClient.directUpdate(CloudSolrClient.java:551)
at org.apache.solr.client.solrj.impl.CloudSolrClient.sendRequest(CloudSolrClient.java:1015)
at org.apache.solr.client.solrj.impl.CloudSolrClient.requestWithRetryOnStaleState(CloudSolrClient.java:886)
at org.apache.solr.client.solrj.impl.CloudSolrClient.requestWithRetryOnStaleState(CloudSolrClient.java:948)
at org.apache.solr.client.solrj.impl.CloudSolrClient.requestWithRetryOnStaleState(CloudSolrClient.java:948)
at org.apache.solr.client.solrj.impl.CloudSolrClient.requestWithRetryOnStaleState(CloudSolrClient.java:948)
at org.apache.solr.client.solrj.impl.CloudSolrClient.requestWithRetryOnStaleState(CloudSolrClient.java:948)
at org.apache.solr.client.solrj.impl.CloudSolrClient.requestWithRetryOnStaleState(CloudSolrClient.java:948)
at org.apache.solr.client.solrj.impl.CloudSolrClient.request(CloudSolrClient.java:819)
at org.apache.solr.client.solrj.SolrRequest.process(SolrRequest.java:194)
at org.apache.solr.client.solrj.request.UpdateRequest.commit(UpdateRequest.java:233)
at org.apache.solr.cloud.api.collections.CollectionsAPIDistributedZkTest.testCollectionsAPI(CollectionsAPIDistributedZkTest.java:464)
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)
Caused by: org.apache.solr.client.solrj.impl.HttpSolrClient$RemoteSolrException: Error from server at http://127.0.0.1:36605/solr/awhollynewcollection_0_shard2_replica_n6: ClusterState says we are the leader (http://127.0.0.1:36605/solr/awhollynewcollection_0_shard2_replica_n6), but locally we don't think so. Request came from null
at org.apache.solr.client.solrj.impl.HttpSolrClient.executeMethod(HttpSolrClient.java:643)
at org.apache.solr.client.solrj.impl.HttpSolrClient.request(HttpSolrClient.java:255)
at org.apache.solr.client.solrj.impl.HttpSolrClient.request(HttpSolrClient.java:244)
at org.apache.solr.client.solrj.impl.LBHttpSolrClient.doRequest(LBHttpSolrClient.java:483)
at org.apache.solr.client.solrj.impl.LBHttpSolrClient.request(LBHttpSolrClient.java:413)
at org.apache.solr.client.solrj.impl.CloudSolrClient.lambda$directUpdate$0(CloudSolrClient.java:528)
at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264)
at org.apache.solr.common.util.ExecutorUtil$MDCAwareThreadPoolExecutor.lambda$execute$0(ExecutorUtil.java:209)
at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1135)
at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635)
... 1 more
Build Log:
[...truncated 13661 lines...]
[junit4] Suite: org.apache.solr.cloud.api.collections.CollectionsAPIDistributedZkTest
[junit4] 2> 819097 INFO (SUITE-CollectionsAPIDistributedZkTest-seed#[97ECC742B916BBB3]-worker) [ ] o.a.s.SolrTestCaseJ4 SecureRandom sanity checks: test.solr.allowed.securerandom=null & java.security.egd=file:/dev/./urandom
[junit4] 2> Creating dataDir: /home/jenkins/workspace/Lucene-Solr-7.x-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.api.collections.CollectionsAPIDistributedZkTest_97ECC742B916BBB3-001/init-core-data-001
[junit4] 2> 819098 WARN (SUITE-CollectionsAPIDistributedZkTest-seed#[97ECC742B916BBB3]-worker) [ ] o.a.s.SolrTestCaseJ4 startTrackingSearchers: numOpens=4 numCloses=4
[junit4] 2> 819098 INFO (SUITE-CollectionsAPIDistributedZkTest-seed#[97ECC742B916BBB3]-worker) [ ] o.a.s.SolrTestCaseJ4 Using PointFields (NUMERIC_POINTS_SYSPROP=true) w/NUMERIC_DOCVALUES_SYSPROP=false
[junit4] 2> 819098 INFO (SUITE-CollectionsAPIDistributedZkTest-seed#[97ECC742B916BBB3]-worker) [ ] o.a.s.SolrTestCaseJ4 Randomized ssl (false) and clientAuth (true) via: @org.apache.solr.util.RandomizeSSL(reason="", ssl=0.0/0.0, value=0.0/0.0, clientAuth=0.0/0.0)
[junit4] 2> 819099 INFO (SUITE-CollectionsAPIDistributedZkTest-seed#[97ECC742B916BBB3]-worker) [ ] o.a.s.c.MiniSolrCloudCluster Starting cluster of 4 servers in /home/jenkins/workspace/Lucene-Solr-7.x-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.api.collections.CollectionsAPIDistributedZkTest_97ECC742B916BBB3-001/tempDir-001
[junit4] 2> 819099 INFO (SUITE-CollectionsAPIDistributedZkTest-seed#[97ECC742B916BBB3]-worker) [ ] o.a.s.c.ZkTestServer STARTING ZK TEST SERVER
[junit4] 2> 819099 INFO (Thread-2042) [ ] o.a.s.c.ZkTestServer client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 819099 INFO (Thread-2042) [ ] o.a.s.c.ZkTestServer Starting server
[junit4] 2> 819103 ERROR (Thread-2042) [ ] 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> 819199 INFO (SUITE-CollectionsAPIDistributedZkTest-seed#[97ECC742B916BBB3]-worker) [ ] o.a.s.c.ZkTestServer start zk server on port:46347
[junit4] 2> 819201 INFO (zkConnectionManagerCallback-6469-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 819204 INFO (jetty-launcher-6466-thread-1) [ ] o.e.j.s.Server jetty-9.4.11.v20180605; built: 2018-06-05T18:24:03.829Z; git: d5fc0523cfa96bfebfbda19606cad384d772f04c; jvm 10.0.1+10
[junit4] 2> 819204 INFO (jetty-launcher-6466-thread-4) [ ] o.e.j.s.Server jetty-9.4.11.v20180605; built: 2018-06-05T18:24:03.829Z; git: d5fc0523cfa96bfebfbda19606cad384d772f04c; jvm 10.0.1+10
[junit4] 2> 819204 INFO (jetty-launcher-6466-thread-2) [ ] o.e.j.s.Server jetty-9.4.11.v20180605; built: 2018-06-05T18:24:03.829Z; git: d5fc0523cfa96bfebfbda19606cad384d772f04c; jvm 10.0.1+10
[junit4] 2> 819204 INFO (jetty-launcher-6466-thread-3) [ ] o.e.j.s.Server jetty-9.4.11.v20180605; built: 2018-06-05T18:24:03.829Z; git: d5fc0523cfa96bfebfbda19606cad384d772f04c; jvm 10.0.1+10
[junit4] 2> 819205 INFO (jetty-launcher-6466-thread-4) [ ] o.e.j.s.session DefaultSessionIdManager workerName=node0
[junit4] 2> 819205 INFO (jetty-launcher-6466-thread-4) [ ] o.e.j.s.session No SessionScavenger set, using defaults
[junit4] 2> 819205 INFO (jetty-launcher-6466-thread-4) [ ] o.e.j.s.session node0 Scavenging every 600000ms
[junit4] 2> 819205 INFO (jetty-launcher-6466-thread-1) [ ] o.e.j.s.session DefaultSessionIdManager workerName=node0
[junit4] 2> 819206 INFO (jetty-launcher-6466-thread-1) [ ] o.e.j.s.session No SessionScavenger set, using defaults
[junit4] 2> 819206 INFO (jetty-launcher-6466-thread-3) [ ] o.e.j.s.session DefaultSessionIdManager workerName=node0
[junit4] 2> 819206 INFO (jetty-launcher-6466-thread-1) [ ] o.e.j.s.session node0 Scavenging every 660000ms
[junit4] 2> 819206 INFO (jetty-launcher-6466-thread-3) [ ] o.e.j.s.session No SessionScavenger set, using defaults
[junit4] 2> 819206 INFO (jetty-launcher-6466-thread-3) [ ] o.e.j.s.session node0 Scavenging every 660000ms
[junit4] 2> 819206 INFO (jetty-launcher-6466-thread-4) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@45f9f58d{/solr,null,AVAILABLE}
[junit4] 2> 819206 INFO (jetty-launcher-6466-thread-1) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@5a9435f{/solr,null,AVAILABLE}
[junit4] 2> 819207 INFO (jetty-launcher-6466-thread-4) [ ] o.e.j.s.AbstractConnector Started ServerConnector@13928cc6{HTTP/1.1,[http/1.1]}{127.0.0.1:۳۵۳۳۵}
[junit4] 2> 819207 INFO (jetty-launcher-6466-thread-4) [ ] o.e.j.s.Server Started @۸۱۹۲۴۰ms
[junit4] 2> 819207 INFO (jetty-launcher-6466-thread-4) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=35335}
[junit4] 2> 819207 ERROR (jetty-launcher-6466-thread-4) [ ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 819207 INFO (jetty-launcher-6466-thread-4) [ ] o.a.s.s.SolrDispatchFilter Using logger factory org.apache.logging.slf4j.Log4jLoggerFactory
[junit4] 2> 819207 INFO (jetty-launcher-6466-thread-4) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr™ version 7.5.0
[junit4] 2> 819207 INFO (jetty-launcher-6466-thread-4) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 819207 INFO (jetty-launcher-6466-thread-4) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 819207 INFO (jetty-launcher-6466-thread-4) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2018-08-11T20:25:39.303401Z
[junit4] 2> 819207 INFO (jetty-launcher-6466-thread-3) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@1871adb0{/solr,null,AVAILABLE}
[junit4] 2> 819208 INFO (jetty-launcher-6466-thread-3) [ ] o.e.j.s.AbstractConnector Started ServerConnector@48d9e8af{HTTP/1.1,[http/1.1]}{127.0.0.1:۳۶۶۰۵}
[junit4] 2> 819208 INFO (jetty-launcher-6466-thread-3) [ ] o.e.j.s.Server Started @۸۱۹۲۴۱ms
[junit4] 2> 819208 INFO (jetty-launcher-6466-thread-3) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=36605}
[junit4] 2> 819208 INFO (jetty-launcher-6466-thread-1) [ ] o.e.j.s.AbstractConnector Started ServerConnector@4b469d6f{HTTP/1.1,[http/1.1]}{127.0.0.1:۳۹۱۲۱}
[junit4] 2> 819208 INFO (jetty-launcher-6466-thread-1) [ ] o.e.j.s.Server Started @۸۱۹۲۴۱ms
[junit4] 2> 819208 INFO (jetty-launcher-6466-thread-1) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=39121}
[junit4] 2> 819208 ERROR (jetty-launcher-6466-thread-3) [ ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 819208 INFO (jetty-launcher-6466-thread-3) [ ] o.a.s.s.SolrDispatchFilter Using logger factory org.apache.logging.slf4j.Log4jLoggerFactory
[junit4] 2> 819208 INFO (jetty-launcher-6466-thread-3) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr™ version 7.5.0
[junit4] 2> 819208 INFO (jetty-launcher-6466-thread-3) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 819208 INFO (jetty-launcher-6466-thread-3) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 819208 ERROR (jetty-launcher-6466-thread-1) [ ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 819208 INFO (jetty-launcher-6466-thread-3) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2018-08-11T20:25:39.304560Z
[junit4] 2> 819208 INFO (jetty-launcher-6466-thread-1) [ ] o.a.s.s.SolrDispatchFilter Using logger factory org.apache.logging.slf4j.Log4jLoggerFactory
[junit4] 2> 819208 INFO (jetty-launcher-6466-thread-1) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr™ version 7.5.0
[junit4] 2> 819208 INFO (jetty-launcher-6466-thread-1) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 819208 INFO (jetty-launcher-6466-thread-2) [ ] o.e.j.s.session DefaultSessionIdManager workerName=node0
[junit4] 2> 819208 INFO (jetty-launcher-6466-thread-1) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 819208 INFO (jetty-launcher-6466-thread-2) [ ] o.e.j.s.session No SessionScavenger set, using defaults
[junit4] 2> 819208 INFO (jetty-launcher-6466-thread-1) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2018-08-11T20:25:39.304658Z
[junit4] 2> 819208 INFO (jetty-launcher-6466-thread-2) [ ] o.e.j.s.session node0 Scavenging every 660000ms
[junit4] 2> 819208 INFO (zkConnectionManagerCallback-6471-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 819209 INFO (jetty-launcher-6466-thread-4) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 819209 INFO (zkConnectionManagerCallback-6475-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 819209 INFO (jetty-launcher-6466-thread-2) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@790c9859{/solr,null,AVAILABLE}
[junit4] 2> 819209 INFO (zkConnectionManagerCallback-6473-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 819209 INFO (jetty-launcher-6466-thread-1) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 819209 INFO (jetty-launcher-6466-thread-2) [ ] o.e.j.s.AbstractConnector Started ServerConnector@d49771b{HTTP/1.1,[http/1.1]}{127.0.0.1:۴۰۸۶۱}
[junit4] 2> 819209 INFO (jetty-launcher-6466-thread-3) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 819209 INFO (jetty-launcher-6466-thread-2) [ ] o.e.j.s.Server Started @۸۱۹۲۴۳ms
[junit4] 2> 819209 INFO (jetty-launcher-6466-thread-2) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=40861}
[junit4] 2> 819210 ERROR (jetty-launcher-6466-thread-2) [ ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 819210 INFO (jetty-launcher-6466-thread-2) [ ] o.a.s.s.SolrDispatchFilter Using logger factory org.apache.logging.slf4j.Log4jLoggerFactory
[junit4] 2> 819210 INFO (jetty-launcher-6466-thread-2) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr™ version 7.5.0
[junit4] 2> 819210 INFO (jetty-launcher-6466-thread-2) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 819210 INFO (jetty-launcher-6466-thread-2) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 819210 INFO (jetty-launcher-6466-thread-2) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2018-08-11T20:25:39.306128Z
[junit4] 2> 819217 INFO (zkConnectionManagerCallback-6477-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 819217 INFO (jetty-launcher-6466-thread-4) [ ] o.a.s.c.SolrXmlConfig Configuration parameter autoReplicaFailoverWorkLoopDelay is ignored
[junit4] 2> 819217 INFO (jetty-launcher-6466-thread-4) [ ] o.a.s.c.SolrXmlConfig Configuration parameter autoReplicaFailoverBadNodeExpiration is ignored
[junit4] 2> 819217 INFO (jetty-launcher-6466-thread-3) [ ] o.a.s.c.SolrXmlConfig Configuration parameter autoReplicaFailoverWorkLoopDelay is ignored
[junit4] 2> 819217 INFO (jetty-launcher-6466-thread-1) [ ] o.a.s.c.SolrXmlConfig Configuration parameter autoReplicaFailoverWorkLoopDelay is ignored
[junit4] 2> 819217 INFO (jetty-launcher-6466-thread-3) [ ] o.a.s.c.SolrXmlConfig Configuration parameter autoReplicaFailoverBadNodeExpiration is ignored
[junit4] 2> 819217 INFO (jetty-launcher-6466-thread-1) [ ] o.a.s.c.SolrXmlConfig Configuration parameter autoReplicaFailoverBadNodeExpiration is ignored
[junit4] 2> 819217 INFO (jetty-launcher-6466-thread-2) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 819220 INFO (jetty-launcher-6466-thread-2) [ ] o.a.s.c.SolrXmlConfig Configuration parameter autoReplicaFailoverWorkLoopDelay is ignored
[junit4] 2> 819220 INFO (jetty-launcher-6466-thread-2) [ ] o.a.s.c.SolrXmlConfig Configuration parameter autoReplicaFailoverBadNodeExpiration is ignored
[junit4] 2> 819242 INFO (jetty-launcher-6466-thread-4) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:46347/solr
[junit4] 2> 819243 INFO (zkConnectionManagerCallback-6481-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 819244 INFO (zkConnectionManagerCallback-6483-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 819277 INFO (jetty-launcher-6466-thread-2) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:46347/solr
[junit4] 2> 819277 INFO (jetty-launcher-6466-thread-4) [n:127.0.0.1:35335_solr ] o.a.s.c.OverseerElectionContext I am going to be the leader 127.0.0.1:35335_solr
[junit4] 2> 819277 INFO (zkConnectionManagerCallback-6489-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 819277 INFO (jetty-launcher-6466-thread-4) [n:127.0.0.1:35335_solr ] o.a.s.c.Overseer Overseer (id=72144194885451782-127.0.0.1:35335_solr-n_0000000000) starting
[junit4] 2> 819278 INFO (zkConnectionManagerCallback-6491-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 819280 INFO (zkConnectionManagerCallback-6498-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 819281 INFO (jetty-launcher-6466-thread-4) [n:127.0.0.1:35335_solr ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:46347/solr ready
[junit4] 2> 819281 INFO (OverseerStateUpdate-72144194885451782-127.0.0.1:35335_solr-n_0000000000) [ ] o.a.s.c.Overseer Starting to work on the main queue : 127.0.0.1:35335_solr
[junit4] 2> 819282 INFO (jetty-launcher-6466-thread-2) [n:127.0.0.1:40861_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:40861_solr
[junit4] 2> 819285 INFO (jetty-launcher-6466-thread-4) [n:127.0.0.1:35335_solr ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores
[junit4] 2> 819285 INFO (jetty-launcher-6466-thread-4) [n:127.0.0.1:35335_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:35335_solr
[junit4] 2> 819293 INFO (zkCallback-6497-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (2)
[junit4] 2> 819298 INFO (jetty-launcher-6466-thread-4) [n:127.0.0.1:35335_solr ] o.a.s.h.a.MetricsHistoryHandler No .system collection, keeping metrics history in memory.
[junit4] 2> 819298 INFO (zkCallback-6490-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (2)
[junit4] 2> 819298 INFO (OverseerStateUpdate-72144194885451782-127.0.0.1:35335_solr-n_0000000000) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (2)
[junit4] 2> 819299 INFO (jetty-launcher-6466-thread-1) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:46347/solr
[junit4] 2> 819306 INFO (jetty-launcher-6466-thread-4) [n:127.0.0.1:35335_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@75452caf
[junit4] 2> 819308 INFO (zkConnectionManagerCallback-6508-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 819308 INFO (zkConnectionManagerCallback-6506-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 819309 INFO (jetty-launcher-6466-thread-2) [n:127.0.0.1:40861_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (2)
[junit4] 2> 819309 INFO (jetty-launcher-6466-thread-2) [n:127.0.0.1:40861_solr ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:46347/solr ready
[junit4] 2> 819311 INFO (jetty-launcher-6466-thread-4) [n:127.0.0.1:35335_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@75452caf
[junit4] 2> 819311 INFO (jetty-launcher-6466-thread-4) [n:127.0.0.1:35335_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@75452caf
[junit4] 2> 819311 INFO (jetty-launcher-6466-thread-4) [n:127.0.0.1:35335_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /home/jenkins/workspace/Lucene-Solr-7.x-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.api.collections.CollectionsAPIDistributedZkTest_97ECC742B916BBB3-001/tempDir-001/node4
[junit4] 2> 819315 INFO (jetty-launcher-6466-thread-2) [n:127.0.0.1:40861_solr ] o.a.s.h.a.MetricsHistoryHandler No .system collection, keeping metrics history in memory.
[junit4] 2> 819316 INFO (zkConnectionManagerCallback-6510-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 819319 INFO (jetty-launcher-6466-thread-1) [n:127.0.0.1:39121_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (2)
[junit4] 2> 819321 INFO (jetty-launcher-6466-thread-1) [n:127.0.0.1:39121_solr ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores
[junit4] 2> 819321 INFO (jetty-launcher-6466-thread-1) [n:127.0.0.1:39121_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:39121_solr
[junit4] 2> 819321 INFO (zkCallback-6490-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3)
[junit4] 2> 819321 INFO (zkCallback-6482-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3)
[junit4] 2> 819321 INFO (zkCallback-6497-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3)
[junit4] 2> 819322 INFO (zkCallback-6505-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3)
[junit4] 2> 819322 INFO (zkCallback-6509-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3)
[junit4] 2> 819325 INFO (jetty-launcher-6466-thread-2) [n:127.0.0.1:40861_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@75452caf
[junit4] 2> 819329 INFO (jetty-launcher-6466-thread-2) [n:127.0.0.1:40861_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@75452caf
[junit4] 2> 819329 INFO (jetty-launcher-6466-thread-2) [n:127.0.0.1:40861_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@75452caf
[junit4] 2> 819330 INFO (zkConnectionManagerCallback-6518-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 819330 INFO (jetty-launcher-6466-thread-2) [n:127.0.0.1:40861_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /home/jenkins/workspace/Lucene-Solr-7.x-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.api.collections.CollectionsAPIDistributedZkTest_97ECC742B916BBB3-001/tempDir-001/node2
[junit4] 2> 819331 INFO (jetty-launcher-6466-thread-1) [n:127.0.0.1:39121_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (3)
[junit4] 2> 819331 INFO (jetty-launcher-6466-thread-1) [n:127.0.0.1:39121_solr ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:46347/solr ready
[junit4] 2> 819332 INFO (jetty-launcher-6466-thread-1) [n:127.0.0.1:39121_solr ] o.a.s.h.a.MetricsHistoryHandler No .system collection, keeping metrics history in memory.
[junit4] 2> 819341 INFO (jetty-launcher-6466-thread-1) [n:127.0.0.1:39121_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@75452caf
[junit4] 2> 819345 INFO (jetty-launcher-6466-thread-1) [n:127.0.0.1:39121_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@75452caf
[junit4] 2> 819346 INFO (jetty-launcher-6466-thread-1) [n:127.0.0.1:39121_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@75452caf
[junit4] 2> 819346 INFO (jetty-launcher-6466-thread-1) [n:127.0.0.1:39121_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /home/jenkins/workspace/Lucene-Solr-7.x-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.api.collections.CollectionsAPIDistributedZkTest_97ECC742B916BBB3-001/tempDir-001/node1
[junit4] 2> 819353 INFO (jetty-launcher-6466-thread-3) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:46347/solr
[junit4] 2> 819354 INFO (zkConnectionManagerCallback-6523-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 819355 INFO (zkConnectionManagerCallback-6525-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 819358 INFO (jetty-launcher-6466-thread-3) [n:127.0.0.1:36605_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (3)
[junit4] 2> 819359 INFO (jetty-launcher-6466-thread-3) [n:127.0.0.1:36605_solr ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores
[junit4] 2> 819360 INFO (jetty-launcher-6466-thread-3) [n:127.0.0.1:36605_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:36605_solr
[junit4] 2> 819360 INFO (zkCallback-6482-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4)
[junit4] 2> 819360 INFO (zkCallback-6490-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4)
[junit4] 2> 819360 INFO (zkCallback-6509-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4)
[junit4] 2> 819360 INFO (zkCallback-6497-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4)
[junit4] 2> 819360 INFO (zkCallback-6505-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4)
[junit4] 2> 819361 INFO (zkCallback-6524-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4)
[junit4] 2> 819361 INFO (zkCallback-6517-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4)
[junit4] 2> 819369 INFO (zkConnectionManagerCallback-6532-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 819369 INFO (jetty-launcher-6466-thread-3) [n:127.0.0.1:36605_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (4)
[junit4] 2> 819370 INFO (jetty-launcher-6466-thread-3) [n:127.0.0.1:36605_solr ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:46347/solr ready
[junit4] 2> 819370 INFO (jetty-launcher-6466-thread-3) [n:127.0.0.1:36605_solr ] o.a.s.h.a.MetricsHistoryHandler No .system collection, keeping metrics history in memory.
[junit4] 2> 819378 INFO (jetty-launcher-6466-thread-3) [n:127.0.0.1:36605_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@75452caf
[junit4] 2> 819383 INFO (jetty-launcher-6466-thread-3) [n:127.0.0.1:36605_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@75452caf
[junit4] 2> 819383 INFO (jetty-launcher-6466-thread-3) [n:127.0.0.1:36605_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@75452caf
[junit4] 2> 819384 INFO (jetty-launcher-6466-thread-3) [n:127.0.0.1:36605_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /home/jenkins/workspace/Lucene-Solr-7.x-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.api.collections.CollectionsAPIDistributedZkTest_97ECC742B916BBB3-001/tempDir-001/node3
[junit4] 2> 819403 INFO (zkConnectionManagerCallback-6535-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 819405 INFO (zkConnectionManagerCallback-6540-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 819405 INFO (SUITE-CollectionsAPIDistributedZkTest-seed#[97ECC742B916BBB3]-worker) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (4)
[junit4] 2> 819407 INFO (SUITE-CollectionsAPIDistributedZkTest-seed#[97ECC742B916BBB3]-worker) [ ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:46347/solr ready
[junit4] 2> 819420 INFO (TEST-CollectionsAPIDistributedZkTest.deleteCollectionRemovesStaleZkCollectionsNode-seed#[97ECC742B916BBB3]) [ ] o.a.s.SolrTestCaseJ4 ###Starting deleteCollectionRemovesStaleZkCollectionsNode
[junit4] 2> 819421 INFO (TEST-CollectionsAPIDistributedZkTest.deleteCollectionRemovesStaleZkCollectionsNode-seed#[97ECC742B916BBB3]) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (4)
[junit4] 2> 819424 INFO (qtp787236023-16694) [n:127.0.0.1:39121_solr ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :delete with params name=out_of_sync_collection&action=DELETE&wt=javabin&version=2 and sendToOCPQueue=true
[junit4] 2> 819426 INFO (qtp787236023-16694) [n:127.0.0.1:39121_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={name=out_of_sync_collection&action=DELETE&wt=javabin&version=2} status=0 QTime=2
[junit4] 2> 819427 INFO (qtp787236023-16669) [n:127.0.0.1:39121_solr ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :list with params action=LIST&wt=javabin&version=2 and sendToOCPQueue=true
[junit4] 2> 819427 INFO (qtp787236023-16669) [n:127.0.0.1:39121_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={action=LIST&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 819427 INFO (TEST-CollectionsAPIDistributedZkTest.deleteCollectionRemovesStaleZkCollectionsNode-seed#[97ECC742B916BBB3]) [ ] o.a.s.SolrTestCaseJ4 ###Ending deleteCollectionRemovesStaleZkCollectionsNode
[junit4] 2> 819442 INFO (TEST-CollectionsAPIDistributedZkTest.testMissingNumShards-seed#[97ECC742B916BBB3]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testMissingNumShards
[junit4] 2> 819443 INFO (TEST-CollectionsAPIDistributedZkTest.testMissingNumShards-seed#[97ECC742B916BBB3]) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (4)
[junit4] 2> 819444 INFO (qtp787236023-16692) [n:127.0.0.1:39121_solr ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :create with params replicationFactor=10&collection.configName=conf&name=acollection&action=CREATE&wt=javabin&version=2 and sendToOCPQueue=true
[junit4] 2> 819452 INFO (OverseerThreadFactory-5018-thread-2) [ ] o.a.s.c.a.c.CreateCollectionCmd Create collection acollection
[junit4] 2> 819452 INFO (OverseerCollectionConfigSetProcessor-72144194885451782-127.0.0.1:35335_solr-n_0000000000) [ ] 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> 819452 ERROR (OverseerThreadFactory-5018-thread-2) [ ] o.a.s.c.a.c.OverseerCollectionMessageHandler Collection: acollection operation: create failed:org.apache.solr.common.SolrException: numShards is a required param (when using CompositeId router).
[junit4] 2> at org.apache.solr.cloud.api.collections.CreateCollectionCmd.populateShardNames(CreateCollectionCmd.java:407)
[junit4] 2> at org.apache.solr.cloud.api.collections.CreateCollectionCmd.call(CreateCollectionCmd.java:139)
[junit4] 2> at org.apache.solr.cloud.api.collections.OverseerCollectionMessageHandler.processMessage(OverseerCollectionMessageHandler.java:259)
[junit4] 2> at org.apache.solr.cloud.OverseerTaskProcessor$Runner.run(OverseerTaskProcessor.java:473)
[junit4] 2> at org.apache.solr.common.util.ExecutorUtil$MDCAwareThreadPoolExecutor.lambda$execute$0(ExecutorUtil.java:209)
[junit4] 2> at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1135)
[junit4] 2> at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635)
[junit4] 2> at java.base/java.lang.Thread.run(Thread.java:844)
[junit4] 2>
[junit4] 2> 819459 INFO (qtp787236023-16692) [n:127.0.0.1:39121_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={replicationFactor=10&collection.configName=conf&name=acollection&action=CREATE&wt=javabin&version=2} status=400 QTime=14
[junit4] 2> 819459 INFO (TEST-CollectionsAPIDistributedZkTest.testMissingNumShards-seed#[97ECC742B916BBB3]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testMissingNumShards
[junit4] 2> 819474 INFO (TEST-CollectionsAPIDistributedZkTest.testBadActionNames-seed#[97ECC742B916BBB3]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testBadActionNames
[junit4] 2> 819475 INFO (TEST-CollectionsAPIDistributedZkTest.testBadActionNames-seed#[97ECC742B916BBB3]) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (4)
[junit4] 2> 819476 ERROR (qtp787236023-16686) [n:127.0.0.1:39121_solr ] o.a.s.h.RequestHandlerBase org.apache.solr.common.SolrException: Unknown action: BADACTION
[junit4] 2> at org.apache.solr.handler.admin.CollectionsHandler.handleRequestBody(CollectionsHandler.java:241)
[junit4] 2> at org.apache.solr.handler.RequestHandlerBase.handleRequest(RequestHandlerBase.java:199)
[junit4] 2> at org.apache.solr.servlet.HttpSolrCall.handleAdmin(HttpSolrCall.java:734)
[junit4] 2> at org.apache.solr.servlet.HttpSolrCall.handleAdminRequest(HttpSolrCall.java:715)
[junit4] 2> at org.apache.solr.servlet.HttpSolrCall.call(HttpSolrCall.java:496)
[junit4] 2> at org.apache.solr.servlet.SolrDispatchFilter.doFilter(SolrDispatchFilter.java:377)
[junit4] 2> at org.apache.solr.servlet.SolrDispatchFilter.doFilter(SolrDispatchFilter.java:323)
[junit4] 2> at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1642)
[junit4] 2> at org.apache.solr.client.solrj.embedded.JettySolrRunner$DebugFilter.doFilter(JettySolrRunner.java:139)
[junit4] 2> at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1642)
[junit4] 2> at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:533)
[junit4] 2> at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:255)
[junit4] 2> at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:1595)
[junit4] 2> at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:255)
[junit4] 2> at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1317)
[junit4] 2> at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:203)
[junit4] 2> at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:473)
[junit4] 2> at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:1564)
[junit4] 2> at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:201)
[junit4] 2> at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1219)
[junit4] 2> at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:144)
[junit4] 2> at org.eclipse.jetty.server.handler.gzip.GzipHandler.handle(GzipHandler.java:724)
[junit4] 2> at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:132)
[junit4] 2> at org.eclipse.jetty.server.Server.handle(Server.java:531)
[junit4] 2> at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:352)
[junit4] 2> at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:260)
[junit4] 2> at org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:281)
[junit4] 2> at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:102)
[junit4] 2> at org.eclipse.jetty.io.ChannelEndPoint$2.run(ChannelEndPoint.java:118)
[junit4] 2> at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.runTask(EatWhatYouKill.java:333)
[junit4] 2> at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.doProduce(EatWhatYouKill.java:310)
[junit4] 2> at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.tryProduce(EatWhatYouKill.java:168)
[junit4] 2> at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.run(EatWhatYouKill.java:126)
[junit4] 2> at org.eclipse.jetty.util.thread.ReservedThreadExecutor$ReservedThread.run(ReservedThreadExecutor.java:366)
[junit4] 2> at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:762)
[junit4] 2> at org.eclipse.jetty.util.thread.QueuedThreadPool$2.run(QueuedThreadPool.java:680)
[junit4] 2> at java.base/java.lang.Thread.run(Thread.java:844)
[junit4] 2>
[junit4] 2> 819476 INFO (qtp787236023-16686) [n:127.0.0.1:39121_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={name=badactioncollection&action=BADACTION&numShards=2&wt=javabin&version=2} status=400 QTime=0
[junit4] 2> 819477 INFO (TEST-CollectionsAPIDistributedZkTest.testBadActionNames-seed#[97ECC742B916BBB3]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testBadActionNames
[junit4] 2> 819492 INFO (TEST-CollectionsAPIDistributedZkTest.testTooManyReplicas-seed#[97ECC742B916BBB3]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testTooManyReplicas
[junit4] 2> 819493 INFO (TEST-CollectionsAPIDistributedZkTest.testTooManyReplicas-seed#[97ECC742B916BBB3]) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (4)
[junit4] 2> 819494 INFO (qtp787236023-16692) [n:127.0.0.1:39121_solr ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :create with params collection.configName=conf&name=collection&nrtReplicas=10&action=CREATE&numShards=2&wt=javabin&version=2 and sendToOCPQueue=true
[junit4] 2> 819495 INFO (OverseerThreadFactory-5018-thread-3) [ ] o.a.s.c.a.c.CreateCollectionCmd Create collection collection
[junit4] 2> 819495 INFO (OverseerCollectionConfigSetProcessor-72144194885451782-127.0.0.1:35335_solr-n_0000000000) [ ] 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> 819598 WARN (OverseerThreadFactory-5018-thread-3) [ ] o.a.s.c.a.c.CreateCollectionCmd Specified number of replicas of 10 on collection collection is higher than the number of Solr instances currently live or live and part of your createNodeSet(4). It's unusual to run two replica of the same slice on the same Solr-instance.
[junit4] 2> 819598 ERROR (OverseerThreadFactory-5018-thread-3) [ ] o.a.s.c.a.c.OverseerCollectionMessageHandler Collection: collection operation: create failed:org.apache.solr.common.SolrException: Cannot create collection collection. Value of maxShardsPerNode is 1, and the number of nodes currently live or live and part of your createNodeSet is 4. This allows a maximum of 4 to be created. Value of numShards is 2, value of nrtReplicas is 10, value of tlogReplicas is 0 and value of pullReplicas is 0. This requires 20 shards to be created (higher than the allowed number)
[junit4] 2> at org.apache.solr.cloud.api.collections.CreateCollectionCmd.buildReplicaPositions(CreateCollectionCmd.java:364)
[junit4] 2> at org.apache.solr.cloud.api.collections.CreateCollectionCmd.call(CreateCollectionCmd.java:178)
[junit4] 2> at org.apache.solr.cloud.api.collections.OverseerCollectionMessageHandler.processMessage(OverseerCollectionMessageHandler.java:259)
[junit4] 2> at org.apache.solr.cloud.OverseerTaskProcessor$Runner.run(OverseerTaskProcessor.java:473)
[junit4] 2> at org.apache.solr.common.util.ExecutorUtil$MDCAwareThreadPoolExecutor.lambda$execute$0(ExecutorUtil.java:209)
[junit4] 2> at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1135)
[junit4] 2> at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635)
[junit4] 2> at java.base/java.lang.Thread.run(Thread.java:844)
[junit4] 2>
[junit4] 2> 819600 INFO (qtp787236023-16692) [n:127.0.0.1:39121_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={collection.configName=conf&name=collection&nrtReplicas=10&action=CREATE&numShards=2&wt=javabin&version=2} status=400 QTime=106
[junit4] 2> 819601 INFO (TEST-CollectionsAPIDistributedZkTest.testTooManyReplicas-seed#[97ECC742B916BBB3]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testTooManyReplicas
[junit4] 2> 819616 INFO (TEST-CollectionsAPIDistributedZkTest.testZeroNumShards-seed#[97ECC742B916BBB3]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testZeroNumShards
[junit4] 2> 819616 INFO (TEST-CollectionsAPIDistributedZkTest.testZeroNumShards-seed#[97ECC742B916BBB3]) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (4)
[junit4] 2> 819617 INFO (qtp787236023-16686) [n:127.0.0.1:39121_solr ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :delete with params name=collection&action=DELETE&wt=javabin&version=2 and sendToOCPQueue=true
[junit4] 2> 819618 INFO (OverseerCollectionConfigSetProcessor-72144194885451782-127.0.0.1:35335_solr-n_0000000000) [ ] 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> 819618 INFO (OverseerThreadFactory-5018-thread-4) [ ] o.a.s.c.a.c.OverseerCollectionMessageHandler Executing Collection Cmd=action=UNLOAD&deleteInstanceDir=true&deleteDataDir=true&deleteMetricsHistory=true, asyncId=null
[junit4] 2> 820322 INFO (qtp787236023-16686) [n:127.0.0.1:39121_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={name=collection&action=DELETE&wt=javabin&version=2} status=0 QTime=704
[junit4] 2> 820323 INFO (qtp787236023-16692) [n:127.0.0.1:39121_solr ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :create with params replicationFactor=10&collection.configName=conf&name=acollection&action=CREATE&numShards=0&wt=javabin&version=2 and sendToOCPQueue=true
[junit4] 2> 820324 INFO (OverseerThreadFactory-5018-thread-5) [ ] o.a.s.c.a.c.CreateCollectionCmd Create collection acollection
[junit4] 2> 820324 INFO (OverseerCollectionConfigSetProcessor-72144194885451782-127.0.0.1:35335_solr-n_0000000000) [ ] 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> 820324 ERROR (OverseerThreadFactory-5018-thread-5) [ ] o.a.s.c.a.c.OverseerCollectionMessageHandler Collection: acollection operation: create failed:org.apache.solr.common.SolrException: numShards must be > 0
[junit4] 2> at org.apache.solr.cloud.api.collections.CreateCollectionCmd.populateShardNames(CreateCollectionCmd.java:410)
[junit4] 2> at org.apache.solr.cloud.api.collections.CreateCollectionCmd.call(CreateCollectionCmd.java:139)
[junit4] 2> at org.apache.solr.cloud.api.collections.OverseerCollectionMessageHandler.processMessage(OverseerCollectionMessageHandler.java:259)
[junit4] 2> at org.apache.solr.cloud.OverseerTaskProcessor$Runner.run(OverseerTaskProcessor.java:473)
[junit4] 2> at org.apache.solr.common.util.ExecutorUtil$MDCAwareThreadPoolExecutor.lambda$execute$0(ExecutorUtil.java:209)
[junit4] 2> at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1135)
[junit4] 2> at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635)
[junit4] 2> at java.base/java.lang.Thread.run(Thread.java:844)
[junit4] 2>
[junit4] 2> 820326 INFO (qtp787236023-16692) [n:127.0.0.1:39121_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={replicationFactor=10&collection.configName=conf&name=acollection&action=CREATE&numShards=0&wt=javabin&version=2} status=400 QTime=3
[junit4] 2> 820326 INFO (TEST-CollectionsAPIDistributedZkTest.testZeroNumShards-seed#[97ECC742B916BBB3]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testZeroNumShards
[junit4] 2> 820346 INFO (TEST-CollectionsAPIDistributedZkTest.testMissingRequiredParameters-seed#[97ECC742B916BBB3]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testMissingRequiredParameters
[junit4] 2> 820346 INFO (TEST-CollectionsAPIDistributedZkTest.testMissingRequiredParameters-seed#[97ECC742B916BBB3]) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (4)
[junit4] 2> 820348 INFO (qtp787236023-16686) [n:127.0.0.1:39121_solr ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :create with params action=CREATE&numShards=2&wt=javabin&version=2 and sendToOCPQueue=true
[junit4] 2> 820348 ERROR (qtp787236023-16686) [n:127.0.0.1:39121_solr ] o.a.s.h.RequestHandlerBase org.apache.solr.common.SolrException: Missing required parameter: name
[junit4] 2> at org.apache.solr.common.params.RequiredSolrParams.getParams(RequiredSolrParams.java:90)
[junit4] 2> at org.apache.solr.handler.admin.CollectionsHandler.copy(CollectionsHandler.java:1376)
[junit4] 2> at org.apache.solr.handler.admin.CollectionsHandler.copy(CollectionsHandler.java:1390)
[junit4] 2> at org.apache.solr.handler.admin.CollectionsHandler$CollectionOperation.lambda$static$0(CollectionsHandler.java:468)
[junit4] 2> at org.apache.solr.handler.admin.CollectionsHandler$CollectionOperation.execute(CollectionsHandler.java:1171)
[junit4] 2> at org.apache.solr.handler.admin.CollectionsHandler.invokeAction(CollectionsHandler.java:258)
[junit4] 2> at org.apache.solr.handler.admin.CollectionsHandler.handleRequestBody(CollectionsHandler.java:246)
[junit4] 2> at org.apache.solr.handler.RequestHandlerBase.handleRequest(RequestHandlerBase.java:199)
[junit4] 2> at org.apache.solr.servlet.HttpSolrCall.handleAdmin(HttpSolrCall.java:734)
[junit4] 2> at org.apache.solr.servlet.HttpSolrCall.handleAdminRequest(HttpSolrCall.java:715)
[junit4] 2> at org.apache.solr.servlet.HttpSolrCall.call(HttpSolrCall.java:496)
[junit4] 2> at org.apache.solr.servlet.SolrDispatchFilter.doFilter(SolrDispatchFilter.java:377)
[junit4] 2> at org.apache.solr.servlet.SolrDispatchFilter.doFilter(SolrDispatchFilter.java:323)
[junit4] 2> at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1642)
[junit4] 2> at org.apache.solr.client.solrj.embedded.JettySolrRunner$DebugFilter.doFilter(JettySolrRunner.java:139)
[junit4] 2> at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1642)
[junit4] 2> at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:533)
[junit4] 2> at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:255)
[junit4] 2> at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:1595)
[junit4] 2> at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:255)
[junit4] 2> at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1317)
[junit4] 2> at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:203)
[junit4] 2> at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:473)
[junit4] 2> at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:1564)
[junit4] 2> at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:201)
[junit4] 2> at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1219)
[junit4] 2> at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:144)
[junit4] 2> at org.eclipse.jetty.server.handler.gzip.GzipHandler.handle(GzipHandler.java:724)
[junit4] 2> at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:132)
[junit4] 2> at org.eclipse.jetty.server.Server.handle(Server.java:531)
[junit4] 2> at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:352)
[junit4] 2> at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:260)
[junit4] 2> at org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:281)
[junit4] 2> at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:102)
[junit4] 2> at org.eclipse.jetty.io.ChannelEndPoint$2.run(ChannelEndPoint.java:118)
[junit4] 2> at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.runTask(EatWhatYouKill.java:333)
[junit4] 2> at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.doProduce(EatWhatYouKill.java:310)
[junit4] 2> at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.tryProduce(EatWhatYouKill.java:168)
[junit4] 2> at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.run(EatWhatYouKill.java:126)
[junit4] 2> at org.eclipse.jetty.util.thread.ReservedThreadExecutor$ReservedThread.run(ReservedThreadExecutor.java:366)
[junit4] 2> at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:762)
[junit4] 2> at org.eclipse.jetty.util.thread.QueuedThreadPool$2.run(QueuedThreadPool.java:680)
[junit4] 2> at java.base/java.lang.Thread.run(Thread.java:844)
[junit4] 2>
[junit4] 2> 820348 INFO (qtp787236023-16686) [n:127.0.0.1:39121_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={action=CREATE&numShards=2&wt=javabin&version=2} status=400 QTime=0
[junit4] 2> 820349 INFO (TEST-CollectionsAPIDistributedZkTest.testMissingRequiredParameters-seed#[97ECC742B916BBB3]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testMissingRequiredParameters
[junit4] 2> 820366 INFO (TEST-CollectionsAPIDistributedZkTest.testCoresAreDistributedAcrossNodes-seed#[97ECC742B916BBB3]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testCoresAreDistributedAcrossNodes
[junit4] 2> 820367 INFO (TEST-CollectionsAPIDistributedZkTest.testCoresAreDistributedAcrossNodes-seed#[97ECC742B916BBB3]) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (4)
[junit4] 2> 820368 INFO (qtp787236023-16692) [n:127.0.0.1:39121_solr ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :create with params collection.configName=conf&name=nodes_used_collection&nrtReplicas=2&action=CREATE&numShards=2&wt=javabin&version=2 and sendToOCPQueue=true
[junit4] 2> 820369 INFO (OverseerThreadFactory-5018-thread-5) [ ] o.a.s.c.a.c.CreateCollectionCmd Create collection nodes_used_collection
[junit4] 2> 820369 INFO (OverseerCollectionConfigSetProcessor-72144194885451782-127.0.0.1:35335_solr-n_0000000000) [ ] o.a.s.c.OverseerTaskQueue Response ZK path: /overseer/collection-queue-work/qnr-0000000008 doesn't exist. Requestor may have disconnected from ZooKeeper
[junit4] 2> 820574 INFO (OverseerStateUpdate-72144194885451782-127.0.0.1:35335_solr-n_0000000000) [ ] o.a.s.c.o.SliceMutator createReplica() {
[junit4] 2> "operation":"ADDREPLICA",
[junit4] 2> "collection":"nodes_used_collection",
[junit4] 2> "shard":"shard1",
[junit4] 2> "core":"nodes_used_collection_shard1_replica_n1",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"http://127.0.0.1:36605/solr",
[junit4] 2> "type":"NRT",
[junit4] 2> "waitForFinalState":"false"}
[junit4] 2> 820575 INFO (OverseerStateUpdate-72144194885451782-127.0.0.1:35335_solr-n_0000000000) [ ] o.a.s.c.o.SliceMutator createReplica() {
[junit4] 2> "operation":"ADDREPLICA",
[junit4] 2> "collection":"nodes_used_collection",
[junit4] 2> "shard":"shard1",
[junit4] 2> "core":"nodes_used_collection_shard1_replica_n2",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"http://127.0.0.1:39121/solr",
[junit4] 2> "type":"NRT",
[junit4] 2> "waitForFinalState":"false"}
[junit4] 2> 820576 INFO (OverseerStateUpdate-72144194885451782-127.0.0.1:35335_solr-n_0000000000) [ ] o.a.s.c.o.SliceMutator createReplica() {
[junit4] 2> "operation":"ADDREPLICA",
[junit4] 2> "collection":"nodes_used_collection",
[junit4] 2> "shard":"shard2",
[junit4] 2> "core":"nodes_used_collection_shard2_replica_n4",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"http://127.0.0.1:40861/solr",
[junit4] 2> "type":"NRT",
[junit4] 2> "waitForFinalState":"false"}
[junit4] 2> 820576 INFO (OverseerStateUpdate-72144194885451782-127.0.0.1:35335_solr-n_0000000000) [ ] o.a.s.c.o.SliceMutator createReplica() {
[junit4] 2> "operation":"ADDREPLICA",
[junit4] 2> "collection":"nodes_used_collection",
[junit4] 2> "shard":"shard2",
[junit4] 2> "core":"nodes_used_collection_shard2_replica_n6",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"http://127.0.0.1:35335/solr",
[junit4] 2> "type":"NRT",
[junit4] 2> "waitForFinalState":"false"}
[junit4] 2> 820780 INFO (qtp787236023-16678) [n:127.0.0.1:39121_solr x:nodes_used_collection_shard1_replica_n2] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&coreNodeName=core_node5&collection.configName=conf&newCollection=true&name=nodes_used_collection_shard1_replica_n2&action=CREATE&numShards=2&collection=nodes_used_collection&shard=shard1&wt=javabin&version=2&replicaType=NRT
[junit4] 2> 820786 INFO (qtp751454220-16691) [n:127.0.0.1:36605_solr x:nodes_used_collection_shard1_replica_n1] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&coreNodeName=core_node3&collection.configName=conf&newCollection=true&name=nodes_used_collection_shard1_replica_n1&action=CREATE&numShards=2&collection=nodes_used_collection&shard=shard1&wt=javabin&version=2&replicaType=NRT
[junit4] 2> 820787 INFO (qtp960379684-16682) [n:127.0.0.1:35335_solr x:nodes_used_collection_shard2_replica_n6] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&coreNodeName=core_node8&collection.configName=conf&newCollection=true&name=nodes_used_collection_shard2_replica_n6&action=CREATE&numShards=2&collection=nodes_used_collection&shard=shard2&wt=javabin&version=2&replicaType=NRT
[junit4] 2> 820787 INFO (qtp976889439-16702) [n:127.0.0.1:40861_solr x:nodes_used_collection_shard2_replica_n4] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&coreNodeName=core_node7&collection.configName=conf&newCollection=true&name=nodes_used_collection_shard2_replica_n4&action=CREATE&numShards=2&collection=nodes_used_collection&shard=shard2&wt=javabin&version=2&replicaType=NRT
[junit4] 2> 820787 INFO (qtp976889439-16702) [n:127.0.0.1:40861_solr x:nodes_used_collection_shard2_replica_n4] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores
[junit4] 2> 821793 INFO (qtp976889439-16702) [n:127.0.0.1:40861_solr c:nodes_used_collection s:shard2 r:core_node7 x:nodes_used_collection_shard2_replica_n4] o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.5.0
[junit4] 2> 821793 INFO (qtp960379684-16682) [n:127.0.0.1:35335_solr c:nodes_used_collection s:shard2 r:core_node8 x:nodes_used_collection_shard2_replica_n6] o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.5.0
[junit4] 2> 821793 INFO (qtp751454220-16691) [n:127.0.0.1:36605_solr c:nodes_used_collection s:shard1 r:core_node3 x:nodes_used_collection_shard1_replica_n1] o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.5.0
[junit4] 2> 821793 INFO (qtp787236023-16678) [n:127.0.0.1:39121_solr c:nodes_used_collection s:shard1 r:core_node5 x:nodes_used_collection_shard1_replica_n2] o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.5.0
[junit4] 2> 821803 INFO (qtp960379684-16682) [n:127.0.0.1:35335_solr c:nodes_used_collection s:shard2 r:core_node8 x:nodes_used_collection_shard2_replica_n6] o.a.s.s.IndexSchema [nodes_used_collection_shard2_replica_n6] Schema name=minimal
[junit4] 2> 821803 INFO (qtp787236023-16678) [n:127.0.0.1:39121_solr c:nodes_used_collection s:shard1 r:core_node5 x:nodes_used_collection_shard1_replica_n2] o.a.s.s.IndexSchema [nodes_used_collection_shard1_replica_n2] Schema name=minimal
[junit4] 2> 821803 INFO (qtp751454220-16691) [n:127.0.0.1:36605_solr c:nodes_used_collection s:shard1 r:core_node3 x:nodes_used_collection_shard1_replica_n1] o.a.s.s.IndexSchema [nodes_used_collection_shard1_replica_n1] Schema name=minimal
[junit4] 2> 821803 INFO (qtp976889439-16702) [n:127.0.0.1:40861_solr c:nodes_used_collection s:shard2 r:core_node7 x:nodes_used_collection_shard2_replica_n4] o.a.s.s.IndexSchema [nodes_used_collection_shard2_replica_n4] Schema name=minimal
[junit4] 2> 821805 INFO (qtp976889439-16702) [n:127.0.0.1:40861_solr c:nodes_used_collection s:shard2 r:core_node7 x:nodes_used_collection_shard2_replica_n4] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
[junit4] 2> 821805 INFO (qtp787236023-16678) [n:127.0.0.1:39121_solr c:nodes_used_collection s:shard1 r:core_node5 x:nodes_used_collection_shard1_replica_n2] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
[junit4] 2> 821805 INFO (qtp751454220-16691) [n:127.0.0.1:36605_solr c:nodes_used_collection s:shard1 r:core_node3 x:nodes_used_collection_shard1_replica_n1] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
[junit4] 2> 821805 INFO (qtp960379684-16682) [n:127.0.0.1:35335_solr c:nodes_used_collection s:shard2 r:core_node8 x:nodes_used_collection_shard2_replica_n6] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
[junit4] 2> 821805 INFO (qtp751454220-16691) [n:127.0.0.1:36605_solr c:nodes_used_collection s:shard1 r:core_node3 x:nodes_used_collection_shard1_replica_n1] o.a.s.c.CoreContainer Creating SolrCore 'nodes_used_collection_shard1_replica_n1' using configuration from collection nodes_used_collection, trusted=true
[junit4] 2> 821805 INFO (qtp960379684-16682) [n:127.0.0.1:35335_solr c:nodes_used_collection s:shard2 r:core_node8 x:nodes_used_collection_shard2_replica_n6] o.a.s.c.CoreContainer Creating SolrCore 'nodes_used_collection_shard2_replica_n6' using configuration from collection nodes_used_collection, trusted=true
[junit4] 2> 821805 INFO (qtp976889439-16702) [n:127.0.0.1:40861_solr c:nodes_used_collection s:shard2 r:core_node7 x:nodes_used_collection_shard2_replica_n4] o.a.s.c.CoreContainer Creating SolrCore 'nodes_used_collection_shard2_replica_n4' using configuration from collection nodes_used_collection, trusted=true
[junit4] 2> 821805 INFO (qtp787236023-16678) [n:127.0.0.1:39121_solr c:nodes_used_collection s:shard1 r:core_node5 x:nodes_used_collection_shard1_replica_n2] o.a.s.c.CoreContainer Creating SolrCore 'nodes_used_collection_shard1_replica_n2' using configuration from collection nodes_used_collection, trusted=true
[junit4] 2> 821805 INFO (qtp751454220-16691) [n:127.0.0.1:36605_solr c:nodes_used_collection s:shard1 r:core_node3 x:nodes_used_collection_shard1_replica_n1] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.core.nodes_used_collection.shard1.replica_n1' (registry 'solr.core.nodes_used_collection.shard1.replica_n1') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@75452caf
[junit4] 2> 821805 INFO (qtp787236023-16678) [n:127.0.0.1:39121_solr c:nodes_used_collection s:shard1 r:core_node5 x:nodes_used_collection_shard1_replica_n2] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.core.nodes_used_collection.shard1.replica_n2' (registry 'solr.core.nodes_used_collection.shard1.replica_n2') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@75452caf
[junit4] 2> 821805 INFO (qtp960379684-16682) [n:127.0.0.1:35335_solr c:nodes_used_collection s:shard2 r:core_node8 x:nodes_used_collection_shard2_replica_n6] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.core.nodes_used_collection.shard2.replica_n6' (registry 'solr.core.nodes_used_collection.shard2.replica_n6') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@75452caf
[junit4] 2> 821805 INFO (qtp976889439-16702) [n:127.0.0.1:40861_solr c:nodes_used_collection s:shard2 r:core_node7 x:nodes_used_collection_shard2_replica_n4] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.core.nodes_used_collection.shard2.replica_n4' (registry 'solr.core.nodes_used_collection.shard2.replica_n4') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@75452caf
[junit4] 2> 821805 INFO (qtp751454220-16691) [n:127.0.0.1:36605_solr c:nodes_used_collection s:shard1 r:core_node3 x:nodes_used_collection_shard1_replica_n1] o.a.s.c.SolrCore solr.RecoveryStrategy.Builder
[junit4] 2> 821805 INFO (qtp787236023-16678) [n:127.0.0.1:39121_solr c:nodes_used_collection s:shard1 r:core_node5 x:nodes_used_collection_shard1_replica_n2] o.a.s.c.SolrCore solr.RecoveryStrategy.Builder
[junit4] 2> 821805 INFO (qtp976889439-16702) [n:127.0.0.1:40861_solr c:nodes_used_collection s:shard2 r:core_node7 x:nodes_used_collection_shard2_replica_n4] o.a.s.c.SolrCore solr.RecoveryStrategy.Builder
[junit4] 2> 821805 INFO (qtp960379684-16682) [n:127.0.0.1:35335_solr c:nodes_used_collection s:shard2 r:core_node8 x:nodes_used_collection_shard2_replica_n6] o.a.s.c.SolrCore solr.RecoveryStrategy.Builder
[junit4] 2> 821805 INFO (qtp751454220-16691) [n:127.0.0.1:36605_solr c:nodes_used_collection s:shard1 r:core_node3 x:nodes_used_collection_shard1_replica_n1] o.a.s.c.SolrCore [[nodes_used_collection_shard1_replica_n1] ] Opening new SolrCore at [/home/jenkins/workspace/Lucene-Solr-7.x-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.api.collections.CollectionsAPIDistributedZkTest_97ECC742B916BBB3-001/tempDir-001/node3/nodes_used_collection_shard1_replica_n1], dataDir=[/home/jenkins/workspace/Lucene-Solr-7.x-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.api.collections.CollectionsAPIDistributedZkTest_97ECC742B916BBB3-001/tempDir-001/node3/nodes_used_collection_shard1_replica_n1/data/]
[junit4] 2> 821805 INFO (qtp787236023-16678) [n:127.0.0.1:39121_solr c:nodes_used_collection s:shard1 r:core_node5 x:nodes_used_collection_shard1_replica_n2] o.a.s.c.SolrCore [[nodes_used_collection_shard1_replica_n2] ] Opening new SolrCore at [/home/jenkins/workspace/Lucene-Solr-7.x-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.api.collections.CollectionsAPIDistributedZkTest_97ECC742B916BBB3-001/tempDir-001/node1/nodes_used_collection_shard1_replica_n2], dataDir=[/home/jenkins/workspace/Lucene-Solr-7.x-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.api.collections.CollectionsAPIDistributedZkTest_97ECC742B916BBB3-001/tempDir-001/node1/nodes_used_collection_shard1_replica_n2/data/]
[junit4] 2> 821806 INFO (qtp976889439-16702) [n:127.0.0.1:40861_solr c:nodes_used_collection s:shard2 r:core_node7 x:nodes_used_collection_shard2_replica_n4] o.a.s.c.SolrCore [[nodes_used_collection_shard2_replica_n4] ] Opening new SolrCore at [/home/jenkins/workspace/Lucene-Solr-7.x-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.api.collections.CollectionsAPIDistributedZkTest_97ECC742B916BBB3-001/tempDir-001/node2/nodes_used_collection_shard2_replica_n4], dataDir=[/home/jenkins/workspace/Lucene-Solr-7.x-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.api.collections.CollectionsAPIDistributedZkTest_97ECC742B916BBB3-001/tempDir-001/node2/nodes_used_collection_shard2_replica_n4/data/]
[junit4] 2> 821806 INFO (qtp960379684-16682) [n:127.0.0.1:35335_solr c:nodes_used_collection s:shard2 r:core_node8 x:nodes_used_collection_shard2_replica_n6] o.a.s.c.SolrCore [[nodes_used_collection_shard2_replica_n6] ] Opening new SolrCore at [/home/jenkins/workspace/Lucene-Solr-7.x-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.api.collections.CollectionsAPIDistributedZkTest_97ECC742B916BBB3-001/tempDir-001/node4/nodes_used_collection_shard2_replica_n6], dataDir=[/home/jenkins/workspace/Lucene-Solr-7.x-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.api.collections.CollectionsAPIDistributedZkTest_97ECC742B916BBB3-001/tempDir-001/node4/nodes_used_collection_shard2_replica_n6/data/]
[junit4] 2> 821837 INFO (qtp976889439-16702) [n:127.0.0.1:40861_solr c:nodes_used_collection s:shard2 r:core_node7 x:nodes_used_collection_shard2_replica_n4] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
[junit4] 2> 821837 INFO (qtp960379684-16682) [n:127.0.0.1:35335_solr c:nodes_used_collection s:shard2 r:core_node8 x:nodes_used_collection_shard2_replica_n6] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
[junit4] 2> 821837 INFO (qtp976889439-16702) [n:127.0.0.1:40861_solr c:nodes_used_collection s:shard2 r:core_node7 x:nodes_used_collection_shard2_replica_n4] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 821837 INFO (qtp960379684-16682) [n:127.0.0.1:35335_solr c:nodes_used_collection s:shard2 r:core_node8 x:nodes_used_collection_shard2_replica_n6] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 821838 INFO (qtp976889439-16702) [n:127.0.0.1:40861_solr c:nodes_used_collection s:shard2 r:core_node7 x:nodes_used_collection_shard2_replica_n4] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 821838 INFO (qtp960379684-16682) [n:127.0.0.1:35335_solr c:nodes_used_collection s:shard2 r:core_node8 x:nodes_used_collection_shard2_replica_n6] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 821838 INFO (qtp976889439-16702) [n:127.0.0.1:40861_solr c:nodes_used_collection s:shard2 r:core_node7 x:nodes_used_collection_shard2_replica_n4] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 821838 INFO (qtp960379684-16682) [n:127.0.0.1:35335_solr c:nodes_used_collection s:shard2 r:core_node8 x:nodes_used_collection_shard2_replica_n6] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 821839 INFO (qtp960379684-16682) [n:127.0.0.1:35335_solr c:nodes_used_collection s:shard2 r:core_node8 x:nodes_used_collection_shard2_replica_n6] o.a.s.s.SolrIndexSearcher Opening [Searcher@2bc73af[nodes_used_collection_shard2_replica_n6] main]
[junit4] 2> 821839 INFO (qtp976889439-16702) [n:127.0.0.1:40861_solr c:nodes_used_collection s:shard2 r:core_node7 x:nodes_used_collection_shard2_replica_n4] o.a.s.s.SolrIndexSearcher Opening [Searcher@718255f5[nodes_used_collection_shard2_replica_n4] main]
[junit4] 2> 821839 INFO (qtp960379684-16682) [n:127.0.0.1:35335_solr c:nodes_used_collection s:shard2 r:core_node8 x:nodes_used_collection_shard2_replica_n6] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf
[junit4] 2> 821839 INFO (qtp976889439-16702) [n:127.0.0.1:40861_solr c:nodes_used_collection s:shard2 r:core_node7 x:nodes_used_collection_shard2_replica_n4] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf
[junit4] 2> 821839 INFO (qtp976889439-16702) [n:127.0.0.1:40861_solr c:nodes_used_collection s:shard2 r:core_node7 x:nodes_used_collection_shard2_replica_n4] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf
[junit4] 2> 821840 INFO (qtp960379684-16682) [n:127.0.0.1:35335_solr c:nodes_used_collection s:shard2 r:core_node8 x:nodes_used_collection_shard2_replica_n6] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf
[junit4] 2> 821840 INFO (qtp976889439-16702) [n:127.0.0.1:40861_solr c:nodes_used_collection s:shard2 r:core_node7 x:nodes_used_collection_shard2_replica_n4] o.a.s.h.ReplicationHandler Commits will be reserved for 10000ms.
[junit4] 2> 821840 INFO (qtp960379684-16682) [n:127.0.0.1:35335_solr c:nodes_used_collection s:shard2 r:core_node8 x:nodes_used_collection_shard2_replica_n6] o.a.s.h.ReplicationHandler Commits will be reserved for 10000ms.
[junit4] 2> 821840 INFO (qtp976889439-16702) [n:127.0.0.1:40861_solr c:nodes_used_collection s:shard2 r:core_node7 x:nodes_used_collection_shard2_replica_n4] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1608535655774683136
[junit4] 2> 821840 INFO (qtp960379684-16682) [n:127.0.0.1:35335_solr c:nodes_used_collection s:shard2 r:core_node8 x:nodes_used_collection_shard2_replica_n6] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1608535655774683136
[junit4] 2> 821840 INFO (searcherExecutor-5043-thread-1-processing-n:127.0.0.1:40861_solr x:nodes_used_collection_shard2_replica_n4 c:nodes_used_collection s:shard2 r:core_node7) [n:127.0.0.1:40861_solr c:nodes_used_collection s:shard2 r:core_node7 x:nodes_used_collection_shard2_replica_n4] o.a.s.c.SolrCore [nodes_used_collection_shard2_replica_n4] Registered new searcher Searcher@718255f5[nodes_used_collection_shard2_replica_n4] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 821840 INFO (searcherExecutor-5042-thread-1-processing-n:127.0.0.1:35335_solr x:nodes_used_collection_shard2_replica_n6 c:nodes_used_collection s:shard2 r:core_node8) [n:127.0.0.1:35335_solr c:nodes_used_collection s:shard2 r:core_node8 x:nodes_used_collection_shard2_replica_n6] o.a.s.c.SolrCore [nodes_used_collection_shard2_replica_n6] Registered new searcher Searcher@2bc73af[nodes_used_collection_shard2_replica_n6] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 821843 INFO (qtp960379684-16682) [n:127.0.0.1:35335_solr c:nodes_used_collection s:shard2 r:core_node8 x:nodes_used_collection_shard2_replica_n6] o.a.s.c.ZkShardTerms Successful update of terms at /collections/nodes_used_collection/terms/shard2 to Terms{values={core_node8=0}, version=0}
[junit4] 2> 821843 INFO (qtp976889439-16702) [n:127.0.0.1:40861_solr c:nodes_used_collection s:shard2 r:core_node7 x:nodes_used_collection_shard2_replica_n4] o.a.s.c.ZkShardTerms Failed to save terms, version is not a match, retrying
[junit4] 2> 821843 INFO (qtp976889439-16702) [n:127.0.0.1:40861_solr c:nodes_used_collection s:shard2 r:core_node7 x:nodes_used_collection_shard2_replica_n4] o.a.s.c.ZkShardTerms Successful update of terms at /collections/nodes_used_collection/terms/shard2 to Terms{values={core_node7=0, core_node8=0}, version=1}
[junit4] 2> 821843 INFO (qtp751454220-16691) [n:127.0.0.1:36605_solr c:nodes_used_collection s:shard1 r:core_node3 x:nodes_used_collection_shard1_replica_n1] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
[junit4] 2> 821844 INFO (qtp751454220-16691) [n:127.0.0.1:36605_solr c:nodes_used_collection s:shard1 r:core_node3 x:nodes_used_collection_shard1_replica_n1] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 821845 INFO (qtp751454220-16691) [n:127.0.0.1:36605_solr c:nodes_used_collection s:shard1 r:core_node3 x:nodes_used_collection_shard1_replica_n1] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 821845 INFO (qtp976889439-16702) [n:127.0.0.1:40861_solr c:nodes_used_collection s:shard2 r:core_node7 x:nodes_used_collection_shard2_replica_n4] o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue.
[junit4] 2> 821845 INFO (qtp976889439-16702) [n:127.0.0.1:40861_solr c:nodes_used_collection s:shard2 r:core_node7 x:nodes_used_collection_shard2_replica_n4] o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync
[junit4] 2> 821845 INFO (qtp751454220-16691) [n:127.0.0.1:36605_solr c:nodes_used_collection s:shard1 r:core_node3 x:nodes_used_collection_shard1_replica_n1] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 821845 INFO (qtp976889439-16702) [n:127.0.0.1:40861_solr c:nodes_used_collection s:shard2 r:core_node7 x:nodes_used_collection_shard2_replica_n4] o.a.s.c.SyncStrategy Sync replicas to http://127.0.0.1:40861/solr/nodes_used_collection_shard2_replica_n4/
[junit4] 2> 821845 INFO (qtp976889439-16702) [n:127.0.0.1:40861_solr c:nodes_used_collection s:shard2 r:core_node7 x:nodes_used_collection_shard2_replica_n4] o.a.s.u.PeerSync PeerSync: core=nodes_used_collection_shard2_replica_n4 url=http://127.0.0.1:40861/solr START replicas=[http://127.0.0.1:35335/solr/nodes_used_collection_shard2_replica_n6/] nUpdates=100
[junit4] 2> 821845 INFO (qtp976889439-16702) [n:127.0.0.1:40861_solr c:nodes_used_collection s:shard2 r:core_node7 x:nodes_used_collection_shard2_replica_n4] o.a.s.u.PeerSync PeerSync: core=nodes_used_collection_shard2_replica_n4 url=http://127.0.0.1:40861/solr DONE. We have no versions. sync failed.
[junit4] 2> 821845 INFO (qtp787236023-16678) [n:127.0.0.1:39121_solr c:nodes_used_collection s:shard1 r:core_node5 x:nodes_used_collection_shard1_replica_n2] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
[junit4] 2> 821845 INFO (qtp787236023-16678) [n:127.0.0.1:39121_solr c:nodes_used_collection s:shard1 r:core_node5 x:nodes_used_collection_shard1_replica_n2] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 821846 INFO (qtp960379684-16672) [n:127.0.0.1:35335_solr c:nodes_used_collection s:shard2 r:core_node8 x:nodes_used_collection_shard2_replica_n6] o.a.s.c.S.Request [nodes_used_collection_shard2_replica_n6] webapp=/solr path=/get params={distrib=false&qt=/get&fingerprint=false&getVersions=100&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 821846 INFO (qtp751454220-16691) [n:127.0.0.1:36605_solr c:nodes_used_collection s:shard1 r:core_node3 x:nodes_used_collection_shard1_replica_n1] o.a.s.s.SolrIndexSearcher Opening [Searcher@74d8002e[nodes_used_collection_shard1_replica_n1] main]
[junit4] 2> 821846 INFO (qtp976889439-16702) [n:127.0.0.1:40861_solr c:nodes_used_collection s:shard2 r:core_node7 x:nodes_used_collection_shard2_replica_n4] o.a.s.c.SyncStrategy Leader's attempt to sync with shard failed, moving to the next candidate
[junit4] 2> 821846 INFO (qtp976889439-16702) [n:127.0.0.1:40861_solr c:nodes_used_collection s:shard2 r:core_node7 x:nodes_used_collection_shard2_replica_n4] 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> 821846 INFO (qtp976889439-16702) [n:127.0.0.1:40861_solr c:nodes_used_collection s:shard2 r:core_node7 x:nodes_used_collection_shard2_replica_n4] o.a.s.c.ShardLeaderElectionContext Found all replicas participating in election, clear LIR
[junit4] 2> 821847 INFO (qtp787236023-16678) [n:127.0.0.1:39121_solr c:nodes_used_collection s:shard1 r:core_node5 x:nodes_used_collection_shard1_replica_n2] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 821847 INFO (qtp787236023-16678) [n:127.0.0.1:39121_solr c:nodes_used_collection s:shard1 r:core_node5 x:nodes_used_collection_shard1_replica_n2] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 821847 INFO (qtp751454220-16691) [n:127.0.0.1:36605_solr c:nodes_used_collection s:shard1 r:core_node3 x:nodes_used_collection_shard1_replica_n1] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf
[junit4] 2> 821847 INFO (qtp751454220-16691) [n:127.0.0.1:36605_solr c:nodes_used_collection s:shard1 r:core_node3 x:nodes_used_collection_shard1_replica_n1] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf
[junit4] 2> 821847 INFO (qtp751454220-16691) [n:127.0.0.1:36605_solr c:nodes_used_collection s:shard1 r:core_node3 x:nodes_used_collection_shard1_replica_n1] o.a.s.h.ReplicationHandler Commits will be reserved for 10000ms.
[junit4] 2> 821848 INFO (qtp751454220-16691) [n:127.0.0.1:36605_solr c:nodes_used_collection s:shard1 r:core_node3 x:nodes_used_collection_shard1_replica_n1] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1608535655783071744
[junit4] 2> 821848 INFO (qtp976889439-16702) [n:127.0.0.1:40861_solr c:nodes_used_collection s:shard2 r:core_node7 x:nodes_used_collection_shard2_replica_n4] o.a.s.c.ShardLeaderElectionContext I am the new leader: http://127.0.0.1:40861/solr/nodes_used_collection_shard2_replica_n4/ shard2
[junit4] 2> 821848 INFO (qtp787236023-16678) [n:127.0.0.1:39121_solr c:nodes_used_collection s:shard1 r:core_node5 x:nodes_used_collection_shard1_replica_n2] o.a.s.s.SolrIndexSearcher Opening [Searcher@373ae899[nodes_used_collection_shard1_replica_n2] main]
[junit4] 2> 821848 INFO (searcherExecutor-5041-thread-1-processing-n:127.0.0.1:36605_solr x:nodes_used_collection_shard1_replica_n1 c:nodes_used_collection s:shard1 r:core_node3) [n:127.0.0.1:36605_solr c:nodes_used_collection s:shard1 r:core_node3 x:nodes_used_collection_shard1_replica_n1] o.a.s.c.SolrCore [nodes_used_collection_shard1_replica_n1] Registered new searcher Searcher@74d8002e[nodes_used_collection_shard1_replica_n1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 821848 INFO (qtp787236023-16678) [n:127.0.0.1:39121_solr c:nodes_used_collection s:shard1 r:core_node5 x:nodes_used_collection_shard1_replica_n2] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf
[junit4] 2> 821849 INFO (qtp787236023-16678) [n:127.0.0.1:39121_solr c:nodes_used_collection s:shard1 r:core_node5 x:nodes_used_collection_shard1_replica_n2] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf
[junit4] 2> 821849 INFO (qtp787236023-16678) [n:127.0.0.1:39121_solr c:nodes_used_collection s:shard1 r:core_node5 x:nodes_used_collection_shard1_replica_n2] o.a.s.h.ReplicationHandler Commits will be reserved for 10000ms.
[junit4] 2> 821849 INFO (searcherExecutor-5044-thread-1-processing-n:127.0.0.1:39121_solr x:nodes_used_collection_shard1_replica_n2 c:nodes_used_collection s:shard1 r:core_node5) [n:127.0.0.1:39121_solr c:nodes_used_collection s:shard1 r:core_node5 x:nodes_used_collection_shard1_replica_n2] o.a.s.c.SolrCore [nodes_used_collection_shard1_replica_n2] Registered new searcher Searcher@373ae899[nodes_used_collection_shard1_replica_n2] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 821849 INFO (qtp787236023-16678) [n:127.0.0.1:39121_solr c:nodes_used_collection s:shard1 r:core_node5 x:nodes_used_collection_shard1_replica_n2] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1608535655784120320
[junit4] 2> 821850 INFO (qtp751454220-16691) [n:127.0.0.1:36605_solr c:nodes_used_collection s:shard1 r:core_node3 x:nodes_used_collection_shard1_replica_n1] o.a.s.c.ZkShardTerms Successful update of terms at /collections/nodes_used_collection/terms/shard1 to Terms{values={core_node3=0}, version=0}
[junit4] 2> 821851 INFO (qtp751454220-16691) [n:127.0.0.1:36605_solr c:nodes_used_collection s:shard1 r:core_node3 x:nodes_used_collection_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> 821852 INFO (qtp787236023-16678) [n:127.0.0.1:39121_solr c:nodes_used_collection s:shard1 r:core_node5 x:nodes_used_collection_shard1_replica_n2] o.a.s.c.ZkShardTerms Successful update of terms at /collections/nodes_used_collection/terms/shard1 to Terms{values={core_node3=0, core_node5=0}, version=1}
[junit4] 2> 822001 INFO (qtp976889439-16702) [n:127.0.0.1:40861_solr c:nodes_used_collection s:shard2 r:core_node7 x:nodes_used_collection_shard2_replica_n4] o.a.s.c.ZkController I am the leader, no recovery necessary
[junit4] 2> 822002 INFO (qtp976889439-16702) [n:127.0.0.1:40861_solr c:nodes_used_collection s:shard2 r:core_node7 x:nodes_used_collection_shard2_replica_n4] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={qt=/admin/cores&coreNodeName=core_node7&collection.configName=conf&newCollection=true&name=nodes_used_collection_shard2_replica_n4&action=CREATE&numShards=2&collection=nodes_used_collection&shard=shard2&wt=javabin&version=2&replicaType=NRT} status=0 QTime=1215
[junit4] 2> 822103 INFO (zkCallback-6490-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/nodes_used_collection/state.json] for collection [nodes_used_collection] has occurred - updating... (live nodes size: [4])
[junit4] 2> 822352 INFO (qtp751454220-16691) [n:127.0.0.1:36605_solr c:nodes_used_collection s:shard1 r:core_node3 x:nodes_used_collection_shard1_replica_n1] o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue.
[junit4] 2> 822352 INFO (qtp751454220-16691) [n:127.0.0.1:36605_solr c:nodes_used_collection s:shard1 r:core_node3 x:nodes_used_collection_shard1_replica_n1] o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync
[junit4] 2> 822352 INFO (qtp751454220-16691) [n:127.0.0.1:36605_solr c:nodes_used_collection s:shard1 r:core_node3 x:nodes_used_collection_shard1_replica_n1] o.a.s.c.SyncStrategy Sync replicas to http://127.0.0.1:36605/solr/nodes_used_collection_shard1_replica_n1/
[junit4] 2> 822352 INFO (qtp751454220-16691) [n:127.0.0.1:36605_solr c:nodes_used_collection s:shard1 r:core_node3 x:nodes_used_collection_shard1_replica_n1] o.a.s.u.PeerSync PeerSync: core=nodes_used_collection_shard1_replica_n1 url=http://127.0.0.1:36605/solr START replicas=[http://127.0.0.1:39121/solr/nodes_used_collection_shard1_replica_n2/] nUpdates=100
[junit4] 2> 822353 INFO (qtp751454220-16691) [n:127.0.0.1:36605_solr c:nodes_used_collection s:shard1 r:core_node3 x:nodes_used_collection_shard1_replica_n1] o.a.s.u.PeerSync PeerSync: core=nodes_used_collection_shard1_replica_n1 url=http://127.0.0.1:36605/solr DONE. We have no versions. sync failed.
[junit4] 2> 822354 INFO (qtp787236023-16680) [n:127.0.0.1:39121_solr c:nodes_used_collection s:shard1 r:core_node5 x:nodes_used_collection_shard1_replica_n2] o.a.s.c.S.Request [nodes_used_collection_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> 822354 INFO (qtp751454220-16691) [n:127.0.0.1:36605_solr c:nodes_used_collection s:shard1 r:core_node3 x:nodes_used_collection_shard1_replica_n1] o.a.s.c.SyncStrategy Leader's attempt to sync with shard failed, moving to the next candidate
[junit4] 2> 822354 INFO (qtp751454220-16691) [n:127.0.0.1:36605_solr c:nodes_used_collection s:shard1 r:core_node3 x:nodes_used_collection_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> 822354 INFO (qtp751454220-16691) [n:127.0.0.1:36605_solr c:nodes_used_collection s:shard1 r:core_node3 x:nodes_used_collection_shard1_replica_n1] o.a.s.c.ShardLeaderElectionContext Found all replicas participating in election, clear LIR
[junit4] 2> 822356 INFO (qtp751454220-16691) [n:127.0.0.1:36605_solr c:nodes_used_collection s:shard1 r:core_node3 x:nodes_used_collection_shard1_replica_n1] o.a.s.c.ShardLeaderElectionContext I am the new leader: http://127.0.0.1:36605/solr/nodes_used_collection_shard1_replica_n1/ shard1
[junit4] 2> 822456 INFO (zkCallback-6490-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/nodes_used_collection/state.json] for collection [nodes_used_collection] has occurred - updating... (live nodes size: [4])
[junit4] 2> 822457 INFO (qtp751454220-16691) [n:127.0.0.1:36605_solr c:nodes_used_collection s:shard1 r:core_node3 x:nodes_used_collection_shard1_replica_n1] o.a.s.c.ZkController I am the leader, no recovery necessary
[junit4] 2> 822499 INFO (qtp751454220-16691) [n:127.0.0.1:36605_solr c:nodes_used_collection s:shard1 r:core_node3 x:nodes_used_collection_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=nodes_used_collection_shard1_replica_n1&action=CREATE&numShards=2&collection=nodes_used_collection&shard=shard1&wt=javabin&version=2&replicaT
[...truncated too long message...]
y-5018-thread-5) [ ] o.a.s.c.a.c.OverseerCollectionMessageHandler Collection: reloaded_collection operation: reload failed:java.util.concurrent.RejectedExecutionException: Task org.apache.solr.common.util.ExecutorUtil$MDCAwareThreadPoolExecutor$$Lambda$265/1159893645@2057c48 rejected from org.apache.solr.common.util.ExecutorUtil$MDCAwareThreadPoolExecutor@61401167[Terminated, pool size = 0, active threads = 0, queued tasks = 0, completed tasks = 76]
[junit4] 2> at java.base/java.util.concurrent.ThreadPoolExecutor$AbortPolicy.rejectedExecution(ThreadPoolExecutor.java:2080)
[junit4] 2> at java.base/java.util.concurrent.ThreadPoolExecutor.reject(ThreadPoolExecutor.java:832)
[junit4] 2> at java.base/java.util.concurrent.ThreadPoolExecutor.execute(ThreadPoolExecutor.java:1365)
[junit4] 2> at org.apache.solr.common.util.ExecutorUtil$MDCAwareThreadPoolExecutor.execute(ExecutorUtil.java:194)
[junit4] 2> at com.codahale.metrics.InstrumentedExecutorService.execute(InstrumentedExecutorService.java:61)
[junit4] 2> at java.base/java.util.concurrent.ExecutorCompletionService.submit(ExecutorCompletionService.java:184)
[junit4] 2> at org.apache.solr.handler.component.HttpShardHandler.submit(HttpShardHandler.java:203)
[junit4] 2> at org.apache.solr.cloud.api.collections.OverseerCollectionMessageHandler.waitForCoreAdminAsyncCallToComplete(OverseerCollectionMessageHandler.java:894)
[junit4] 2> at org.apache.solr.cloud.api.collections.OverseerCollectionMessageHandler.waitForAsyncCallsToComplete(OverseerCollectionMessageHandler.java:874)
[junit4] 2> at org.apache.solr.cloud.api.collections.OverseerCollectionMessageHandler.processResponses(OverseerCollectionMessageHandler.java:744)
[junit4] 2> at org.apache.solr.cloud.api.collections.OverseerCollectionMessageHandler.collectionCmd(OverseerCollectionMessageHandler.java:803)
[junit4] 2> at org.apache.solr.cloud.api.collections.OverseerCollectionMessageHandler.collectionCmd(OverseerCollectionMessageHandler.java:783)
[junit4] 2> at org.apache.solr.cloud.api.collections.OverseerCollectionMessageHandler.reloadCollection(OverseerCollectionMessageHandler.java:309)
[junit4] 2> at org.apache.solr.cloud.api.collections.OverseerCollectionMessageHandler.processMessage(OverseerCollectionMessageHandler.java:259)
[junit4] 2> at org.apache.solr.cloud.OverseerTaskProcessor$Runner.run(OverseerTaskProcessor.java:473)
[junit4] 2> at org.apache.solr.common.util.ExecutorUtil$MDCAwareThreadPoolExecutor.lambda$execute$0(ExecutorUtil.java:209)
[junit4] 2> at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1135)
[junit4] 2> at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635)
[junit4] 2> at java.base/java.lang.Thread.run(Thread.java:844)
[junit4] 2>
[junit4] 2> 913866 INFO (OverseerThreadFactory-5018-thread-5) [ ] o.a.s.c.OverseerTaskQueue Response ZK path: /overseer/collection-queue-work/qnr-0000000085 doesn't exist. Requestor may have disconnected from ZooKeeper
[junit4] 2> 913866 WARN (OverseerAutoScalingTriggerThread-72144194885451782-127.0.0.1:35335_solr-n_0000000000) [ ] o.a.s.c.a.OverseerTriggerThread OverseerTriggerThread woken up but we are closed, exiting.
[junit4] 2> 913868 INFO (jetty-closer-6467-thread-1) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@45f9f58d{/solr,null,UNAVAILABLE}
[junit4] 2> 913868 INFO (jetty-closer-6467-thread-1) [ ] o.e.j.s.session node0 Stopped scavenging
[junit4] 2> 914545 INFO (jetty-closer-6467-thread-4) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@7deeec3f{/solr,null,UNAVAILABLE}
[junit4] 2> 914545 INFO (jetty-closer-6467-thread-4) [ ] o.e.j.s.session node0 Stopped scavenging
[junit4] 2> 914545 ERROR (SUITE-CollectionsAPIDistributedZkTest-seed#[97ECC742B916BBB3]-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> 914545 INFO (SUITE-CollectionsAPIDistributedZkTest-seed#[97ECC742B916BBB3]-worker) [ ] o.a.s.c.ZkTestServer connecting to 127.0.0.1:46347 46347
[junit4] 2> 914546 INFO (Thread-2099) [ ] o.a.s.c.ZkTestServer connecting to 127.0.0.1:46347 46347
[junit4] 2> 914546 WARN (Thread-2099) [ ] o.a.s.c.ZkTestServer Watch limit violations:
[junit4] 2> Maximum concurrent create/delete watches above limit:
[junit4] 2>
[junit4] 2> 8 /solr/collections/awhollynewcollection_0/terms/shard2
[junit4] 2> 5 /solr/collections/awhollynewcollection_0/terms/shard1
[junit4] 2> 5 /solr/collections/reloaded_collection/terms/shard1
[junit4] 2> 5 /solr/collections/reloaded_collection/terms/shard2
[junit4] 2> 4 /solr/configs/conf
[junit4] 2>
[junit4] 2> Maximum concurrent data watches above limit:
[junit4] 2>
[junit4] 2> 19 /solr/aliases.json
[junit4] 2> 4 /solr/collections/reloaded_collection/state.json
[junit4] 2>
[junit4] 2> Maximum concurrent children watches above limit:
[junit4] 2>
[junit4] 2> 39 /solr/collections
[junit4] 2>
[junit4] 2> NOTE: leaving temporary files on disk at: /home/jenkins/workspace/Lucene-Solr-7.x-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.api.collections.CollectionsAPIDistributedZkTest_97ECC742B916BBB3-001
[junit4] 2> Aug 11, 2018 8:27:14 PM 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): {id=FST50}, docValues:{}, maxPointsInLeafNode=514, maxMBSortInHeap=5.093595069246113, sim=RandomSimilarity(queryNorm=true): {}, locale=uz-Cyrl, timezone=Europe/Kirov
[junit4] 2> NOTE: Linux 4.15.0-29-generic amd64/Oracle Corporation 10.0.1 (64-bit)/cpus=8,threads=1,free=193135120,total=522715136
[junit4] 2> NOTE: All tests run in this JVM: [MBeansHandlerTest, DirectUpdateHandlerTest, TestCollectionAPI, DistributedVersionInfoTest, TestReload, RequestHandlersTest, PeerSyncWithLeaderAndIndexFingerprintCachingTest, AnalysisAfterCoreReloadTest, TestFieldTypeCollectionResource, DateRangeFieldTest, NumberUtilsTest, TestSQLHandlerNonCloud, AutoscalingHistoryHandlerTest, DirectSolrSpellCheckerTest, ChaosMonkeySafeLeaderWithPullReplicasTest, SimplePostToolTest, CreateCollectionCleanupTest, BigEndianAscendingWordDeserializerTest, TestSubQueryTransformer, DeleteLastCustomShardedReplicaTest, PathHierarchyTokenizerFactoryTest, TestTestInjection, CopyFieldTest, SpatialRPTFieldTypeTest, SyncSliceTest, TestBulkSchemaAPI, EchoParamsTest, TestRetrieveFieldsOptimizer, HdfsBasicDistributedZk2Test, DistribDocExpirationUpdateProcessorTest, TestBadConfig, RemoteQueryErrorTest, SimpleMLTQParserTest, DocValuesTest, QueryParsingTest, TestDFISimilarityFactory, PluginInfoTest, TestCoreAdminApis, TestTriggerIntegration, TestQuerySenderListener, HdfsDirectoryTest, CloudExitableDirectoryReaderTest, DateMathParserTest, IndexSchemaRuntimeFieldTest, TestPullReplicaErrorHandling, DistributedFacetPivotWhiteBoxTest, TestBlendedInfixSuggestions, TestLazyCores, RestoreTriggerStateTest, MissingSegmentRecoveryTest, PropertiesRequestHandlerTest, ZkStateReaderTest, CollectionReloadTest, ResponseLogComponentTest, ConfigureRecoveryStrategyTest, TestLocalFSCloudBackupRestore, DistributedQueryComponentOptimizationTest, AnalysisErrorHandlingTest, DocumentAnalysisRequestHandlerTest, TestAddFieldRealTimeGet, TestFiltering, TestSolrFieldCacheBean, NodeMutatorTest, LargeFieldTest, MoreLikeThisHandlerTest, BlobRepositoryCloudTest, SampleTest, TriggerIntegrationTest, MultiTermTest, TestNoOpRegenerator, BasicDistributedZk2Test, TestSchemaResource, ScheduledTriggerTest, TestManagedSchema, ShardRoutingTest, TestCryptoKeys, TestCSVLoader, TestConfigSets, SolrCoreMetricManagerTest, UnloadDistributedZkTest, SpellingQueryConverterTest, ResponseHeaderTest, TestStressLiveNodes, TestSearcherReuse, ExitableDirectoryReaderTest, ComputePlanActionTest, TestSkipOverseerOperations, SSLMigrationTest, HdfsThreadLeakTest, BlockCacheTest, TestInfoStreamLogging, TestFieldCacheWithThreads, TestDynamicLoading, TestMaxTokenLenTokenizer, TestRemoteStreaming, TestTolerantUpdateProcessorRandomCloud, TestNumericRangeQuery32, CdcrRequestHandlerTest, DistributedFacetSimpleRefinementLongTailTest, TestDynamicFieldResource, DistanceFunctionTest, CollectionsAPIDistributedZkTest]
[junit4] Completed [346/828 (1!)] on J0 in 95.97s, 19 tests, 1 error <<< FAILURES!
[...truncated 43982 lines...]
[repro] Jenkins log URL: https://jenkins.thetaphi.de/job/Lucene-Solr-7.x-Linux/2536/consoleText
[repro] Revision: 6759ba7290304de397f7bcb7ad353feadcebacbb
[repro] Ant options: "-Dargs=-XX:-UseCompressedOops -XX:+UseParallelGC"
[repro] Repro line: ant test -Dtestcase=CollectionsAPIDistributedZkTest -Dtests.method=testCollectionsAPI -Dtests.seed=97ECC742B916BBB3 -Dtests.multiplier=3 -Dtests.slow=true -Dtests.locale=uz-Cyrl -Dtests.timezone=Europe/Kirov -Dtests.asserts=true -Dtests.file.encoding=UTF-8
[repro] ant clean
[...truncated 6 lines...]
[repro] Test suites by module:
[repro] solr/core
[repro] CollectionsAPIDistributedZkTest
[repro] ant compile-test
[...truncated 3413 lines...]
[repro] ant test-nocompile -Dtests.dups=5 -Dtests.maxfailures=5 -Dtests.class="*.CollectionsAPIDistributedZkTest" -Dtests.showOutput=onerror "-Dargs=-XX:-UseCompressedOops -XX:+UseParallelGC" -Dtests.seed=97ECC742B916BBB3 -Dtests.multiplier=3 -Dtests.slow=true -Dtests.locale=uz-Cyrl -Dtests.timezone=Europe/Kirov -Dtests.asserts=true -Dtests.file.encoding=UTF-8
[...truncated 166 lines...]
[repro] Failures:
[repro] 0/5 failed: org.apache.solr.cloud.api.collections.CollectionsAPIDistributedZkTest
[repro] Exiting with code 0
[...truncated 40 lines...]
[JENKINS] Lucene-Solr-7.x-Linux (64bit/jdk1.8.0_172) - Build # 2537
- Still Unstable!
Posted by Policeman Jenkins Server <je...@thetaphi.de>.
Build: https://jenkins.thetaphi.de/job/Lucene-Solr-7.x-Linux/2537/
Java: 64bit/jdk1.8.0_172 -XX:-UseCompressedOops -XX:+UseSerialGC
1 tests failed.
FAILED: org.apache.solr.cloud.AddReplicaTest.test
Error Message:
core_node6:{"core":"addreplicatest_coll_shard1_replica_n5","base_url":"http://127.0.0.1:39343/solr","node_name":"127.0.0.1:39343_solr","state":"active","type":"NRT","force_set_state":"false"}
Stack Trace:
java.lang.AssertionError: core_node6:{"core":"addreplicatest_coll_shard1_replica_n5","base_url":"http://127.0.0.1:39343/solr","node_name":"127.0.0.1:39343_solr","state":"active","type":"NRT","force_set_state":"false"}
at __randomizedtesting.SeedInfo.seed([600A05C720F9336C:E85E3A1D8E055E94]:0)
at org.junit.Assert.fail(Assert.java:93)
at org.junit.Assert.assertTrue(Assert.java:43)
at org.apache.solr.cloud.AddReplicaTest.test(AddReplicaTest.java:85)
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 13459 lines...]
[junit4] Suite: org.apache.solr.cloud.AddReplicaTest
[junit4] 2> Creating dataDir: /home/jenkins/workspace/Lucene-Solr-7.x-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.AddReplicaTest_600A05C720F9336C-001/init-core-data-001
[junit4] 2> 738367 INFO (SUITE-AddReplicaTest-seed#[600A05C720F9336C]-worker) [ ] o.a.s.SolrTestCaseJ4 Using PointFields (NUMERIC_POINTS_SYSPROP=true) w/NUMERIC_DOCVALUES_SYSPROP=true
[junit4] 2> 738368 INFO (SUITE-AddReplicaTest-seed#[600A05C720F9336C]-worker) [ ] o.a.s.SolrTestCaseJ4 Randomized ssl (false) and clientAuth (true) via: @org.apache.solr.util.RandomizeSSL(reason=, ssl=NaN, value=NaN, clientAuth=NaN)
[junit4] 2> 738368 INFO (SUITE-AddReplicaTest-seed#[600A05C720F9336C]-worker) [ ] o.a.s.SolrTestCaseJ4 SecureRandom sanity checks: test.solr.allowed.securerandom=null & java.security.egd=file:/dev/./urandom
[junit4] 2> 738368 INFO (SUITE-AddReplicaTest-seed#[600A05C720F9336C]-worker) [ ] o.a.s.c.MiniSolrCloudCluster Starting cluster of 4 servers in /home/jenkins/workspace/Lucene-Solr-7.x-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.AddReplicaTest_600A05C720F9336C-001/tempDir-001
[junit4] 2> 738368 INFO (SUITE-AddReplicaTest-seed#[600A05C720F9336C]-worker) [ ] o.a.s.c.ZkTestServer STARTING ZK TEST SERVER
[junit4] 2> 738369 INFO (Thread-3792) [ ] o.a.s.c.ZkTestServer client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 738369 INFO (Thread-3792) [ ] o.a.s.c.ZkTestServer Starting server
[junit4] 2> 738370 ERROR (Thread-3792) [ ] 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> 738469 INFO (SUITE-AddReplicaTest-seed#[600A05C720F9336C]-worker) [ ] o.a.s.c.ZkTestServer start zk server on port:38105
[junit4] 2> 738471 INFO (zkConnectionManagerCallback-2529-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 738473 INFO (jetty-launcher-2526-thread-2) [ ] o.e.j.s.Server jetty-9.4.11.v20180605; built: 2018-06-05T18:24:03.829Z; git: d5fc0523cfa96bfebfbda19606cad384d772f04c; jvm 1.8.0_172-b11
[junit4] 2> 738473 INFO (jetty-launcher-2526-thread-1) [ ] o.e.j.s.Server jetty-9.4.11.v20180605; built: 2018-06-05T18:24:03.829Z; git: d5fc0523cfa96bfebfbda19606cad384d772f04c; jvm 1.8.0_172-b11
[junit4] 2> 738473 INFO (jetty-launcher-2526-thread-3) [ ] o.e.j.s.Server jetty-9.4.11.v20180605; built: 2018-06-05T18:24:03.829Z; git: d5fc0523cfa96bfebfbda19606cad384d772f04c; jvm 1.8.0_172-b11
[junit4] 2> 738477 INFO (jetty-launcher-2526-thread-4) [ ] o.e.j.s.Server jetty-9.4.11.v20180605; built: 2018-06-05T18:24:03.829Z; git: d5fc0523cfa96bfebfbda19606cad384d772f04c; jvm 1.8.0_172-b11
[junit4] 2> 738481 INFO (jetty-launcher-2526-thread-2) [ ] o.e.j.s.session DefaultSessionIdManager workerName=node0
[junit4] 2> 738482 INFO (jetty-launcher-2526-thread-2) [ ] o.e.j.s.session No SessionScavenger set, using defaults
[junit4] 2> 738482 INFO (jetty-launcher-2526-thread-2) [ ] o.e.j.s.session node0 Scavenging every 600000ms
[junit4] 2> 738482 INFO (jetty-launcher-2526-thread-4) [ ] o.e.j.s.session DefaultSessionIdManager workerName=node0
[junit4] 2> 738482 INFO (jetty-launcher-2526-thread-4) [ ] o.e.j.s.session No SessionScavenger set, using defaults
[junit4] 2> 738482 INFO (jetty-launcher-2526-thread-2) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@3c2be65f{/solr,null,AVAILABLE}
[junit4] 2> 738482 INFO (jetty-launcher-2526-thread-4) [ ] o.e.j.s.session node0 Scavenging every 600000ms
[junit4] 2> 738482 INFO (jetty-launcher-2526-thread-4) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@273cbeb8{/solr,null,AVAILABLE}
[junit4] 2> 738482 INFO (jetty-launcher-2526-thread-3) [ ] o.e.j.s.session DefaultSessionIdManager workerName=node0
[junit4] 2> 738482 INFO (jetty-launcher-2526-thread-3) [ ] o.e.j.s.session No SessionScavenger set, using defaults
[junit4] 2> 738482 INFO (jetty-launcher-2526-thread-1) [ ] o.e.j.s.session DefaultSessionIdManager workerName=node0
[junit4] 2> 738482 INFO (jetty-launcher-2526-thread-3) [ ] o.e.j.s.session node0 Scavenging every 600000ms
[junit4] 2> 738482 INFO (jetty-launcher-2526-thread-1) [ ] o.e.j.s.session No SessionScavenger set, using defaults
[junit4] 2> 738482 INFO (jetty-launcher-2526-thread-1) [ ] o.e.j.s.session node0 Scavenging every 600000ms
[junit4] 2> 738482 INFO (jetty-launcher-2526-thread-2) [ ] o.e.j.s.AbstractConnector Started ServerConnector@1830589b{HTTP/1.1,[http/1.1]}{127.0.0.1:40385}
[junit4] 2> 738482 INFO (jetty-launcher-2526-thread-4) [ ] o.e.j.s.AbstractConnector Started ServerConnector@6db66c0f{HTTP/1.1,[http/1.1]}{127.0.0.1:46549}
[junit4] 2> 738482 INFO (jetty-launcher-2526-thread-2) [ ] o.e.j.s.Server Started @738507ms
[junit4] 2> 738482 INFO (jetty-launcher-2526-thread-4) [ ] o.e.j.s.Server Started @738507ms
[junit4] 2> 738482 INFO (jetty-launcher-2526-thread-4) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=46549}
[junit4] 2> 738482 INFO (jetty-launcher-2526-thread-2) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=40385}
[junit4] 2> 738482 INFO (jetty-launcher-2526-thread-3) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@13885859{/solr,null,AVAILABLE}
[junit4] 2> 738483 ERROR (jetty-launcher-2526-thread-4) [ ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 738483 INFO (jetty-launcher-2526-thread-4) [ ] o.a.s.s.SolrDispatchFilter Using logger factory org.apache.logging.slf4j.Log4jLoggerFactory
[junit4] 2> 738483 ERROR (jetty-launcher-2526-thread-2) [ ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 738483 INFO (jetty-launcher-2526-thread-2) [ ] o.a.s.s.SolrDispatchFilter Using logger factory org.apache.logging.slf4j.Log4jLoggerFactory
[junit4] 2> 738483 INFO (jetty-launcher-2526-thread-4) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr™ version 7.5.0
[junit4] 2> 738483 INFO (jetty-launcher-2526-thread-2) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr™ version 7.5.0
[junit4] 2> 738483 INFO (jetty-launcher-2526-thread-4) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 738483 INFO (jetty-launcher-2526-thread-2) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 738483 INFO (jetty-launcher-2526-thread-4) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 738483 INFO (jetty-launcher-2526-thread-2) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 738483 INFO (jetty-launcher-2526-thread-4) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2018-08-11T23:18:59.190Z
[junit4] 2> 738483 INFO (jetty-launcher-2526-thread-2) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2018-08-11T23:18:59.190Z
[junit4] 2> 738483 INFO (jetty-launcher-2526-thread-1) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@335a1f5c{/solr,null,AVAILABLE}
[junit4] 2> 738483 INFO (jetty-launcher-2526-thread-3) [ ] o.e.j.s.AbstractConnector Started ServerConnector@71c3f504{HTTP/1.1,[http/1.1]}{127.0.0.1:46639}
[junit4] 2> 738483 INFO (jetty-launcher-2526-thread-3) [ ] o.e.j.s.Server Started @738508ms
[junit4] 2> 738483 INFO (jetty-launcher-2526-thread-3) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=46639}
[junit4] 2> 738483 INFO (jetty-launcher-2526-thread-1) [ ] o.e.j.s.AbstractConnector Started ServerConnector@7f4f123f{HTTP/1.1,[http/1.1]}{127.0.0.1:39343}
[junit4] 2> 738483 ERROR (jetty-launcher-2526-thread-3) [ ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 738483 INFO (jetty-launcher-2526-thread-1) [ ] o.e.j.s.Server Started @738508ms
[junit4] 2> 738483 INFO (jetty-launcher-2526-thread-3) [ ] o.a.s.s.SolrDispatchFilter Using logger factory org.apache.logging.slf4j.Log4jLoggerFactory
[junit4] 2> 738483 INFO (jetty-launcher-2526-thread-1) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=39343}
[junit4] 2> 738483 INFO (jetty-launcher-2526-thread-3) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr™ version 7.5.0
[junit4] 2> 738483 INFO (jetty-launcher-2526-thread-3) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 738483 INFO (jetty-launcher-2526-thread-3) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 738483 INFO (jetty-launcher-2526-thread-3) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2018-08-11T23:18:59.190Z
[junit4] 2> 738483 ERROR (jetty-launcher-2526-thread-1) [ ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 738483 INFO (jetty-launcher-2526-thread-1) [ ] o.a.s.s.SolrDispatchFilter Using logger factory org.apache.logging.slf4j.Log4jLoggerFactory
[junit4] 2> 738483 INFO (jetty-launcher-2526-thread-1) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr™ version 7.5.0
[junit4] 2> 738483 INFO (jetty-launcher-2526-thread-1) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 738483 INFO (jetty-launcher-2526-thread-1) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 738483 INFO (jetty-launcher-2526-thread-1) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2018-08-11T23:18:59.190Z
[junit4] 2> 738485 INFO (zkConnectionManagerCallback-2532-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 738485 INFO (zkConnectionManagerCallback-2533-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 738485 INFO (zkConnectionManagerCallback-2535-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 738485 INFO (zkConnectionManagerCallback-2537-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 738486 INFO (jetty-launcher-2526-thread-2) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 738486 INFO (jetty-launcher-2526-thread-4) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 738486 INFO (jetty-launcher-2526-thread-3) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 738486 INFO (jetty-launcher-2526-thread-1) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 738546 INFO (jetty-launcher-2526-thread-4) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:38105/solr
[junit4] 2> 738547 INFO (zkConnectionManagerCallback-2541-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 738548 DEBUG (jetty-launcher-2526-thread-4) [n:127.0.0.1:46549_solr ] o.a.s.c.ZkController Added new OnReconnect listener org.apache.solr.cloud.ZkController$$Lambda$45/1631193300@4828f3bb
[junit4] 2> 738553 INFO (zkConnectionManagerCallback-2543-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 738601 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: create/delete: /solr/clusterprops.json
[junit4] 2> 738601 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: children: /solr/live_nodes
[junit4] 2> 738601 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: data: /solr/clusterstate.json
[junit4] 2> 738602 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: children: /solr/collections
[junit4] 2> 738602 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: create/delete: /solr/aliases.json
[junit4] 2> 738602 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: create/delete: /solr/security.json
[junit4] 2> 738603 DEBUG (jetty-launcher-2526-thread-4) [n:127.0.0.1:46549_solr ] o.a.s.c.LeaderElector Joined leadership election with path: /overseer_elect/election/72144876451921926-127.0.0.1:46549_solr-n_0000000000
[junit4] 2> 738603 INFO (jetty-launcher-2526-thread-4) [n:127.0.0.1:46549_solr ] o.a.s.c.OverseerElectionContext I am going to be the leader 127.0.0.1:46549_solr
[junit4] 2> 738604 INFO (jetty-launcher-2526-thread-4) [n:127.0.0.1:46549_solr ] o.a.s.c.Overseer Overseer (id=72144876451921926-127.0.0.1:46549_solr-n_0000000000) starting
[junit4] 2> 738607 INFO (zkConnectionManagerCallback-2550-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 738607 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: create/delete: /solr/clusterprops.json
[junit4] 2> 738608 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: children: /solr/live_nodes
[junit4] 2> 738608 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: data: /solr/clusterstate.json
[junit4] 2> 738608 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: children: /solr/collections
[junit4] 2> 738608 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: create/delete: /solr/aliases.json
[junit4] 2> 738608 INFO (jetty-launcher-2526-thread-4) [n:127.0.0.1:46549_solr ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:38105/solr ready
[junit4] 2> 738608 DEBUG (OverseerCollectionConfigSetProcessor-72144876451921926-127.0.0.1:46549_solr-n_0000000000) [ ] o.a.s.c.OverseerTaskProcessor Process current queue of overseer operations
[junit4] 2> 738608 INFO (OverseerStateUpdate-72144876451921926-127.0.0.1:46549_solr-n_0000000000) [ ] o.a.s.c.Overseer Starting to work on the main queue : 127.0.0.1:46549_solr
[junit4] 2> 738609 DEBUG (OverseerCollectionConfigSetProcessor-72144876451921926-127.0.0.1:46549_solr-n_0000000000) [ ] o.a.s.c.OverseerTaskProcessor Cleaning up work-queue. #Running tasks: 0
[junit4] 2> 738609 DEBUG (OverseerCollectionConfigSetProcessor-72144876451921926-127.0.0.1:46549_solr-n_0000000000) [ ] o.a.s.c.OverseerTaskProcessor RunningTasks: []
[junit4] 2> 738609 DEBUG (OverseerCollectionConfigSetProcessor-72144876451921926-127.0.0.1:46549_solr-n_0000000000) [ ] o.a.s.c.OverseerTaskProcessor BlockedTasks: []
[junit4] 2> 738609 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: children: /solr/overseer/queue-work
[junit4] 2> 738609 DEBUG (OverseerCollectionConfigSetProcessor-72144876451921926-127.0.0.1:46549_solr-n_0000000000) [ ] o.a.s.c.OverseerTaskProcessor CompletedTasks: []
[junit4] 2> 738609 DEBUG (OverseerCollectionConfigSetProcessor-72144876451921926-127.0.0.1:46549_solr-n_0000000000) [ ] o.a.s.c.OverseerTaskProcessor RunningZKTasks: []
[junit4] 2> 738609 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: children: /solr/overseer/queue
[junit4] 2> 738609 DEBUG (OverseerCollectionConfigSetProcessor-72144876451921926-127.0.0.1:46549_solr-n_0000000000) [ ] o.a.s.c.OverseerTaskQueue Peeking for top 100 elements. ExcludeSet: []
[junit4] 2> 738609 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: children: /solr/overseer/collection-queue-work
[junit4] 2> 738609 INFO (jetty-launcher-2526-thread-4) [n:127.0.0.1:46549_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:46549_solr
[junit4] 2> 738609 DEBUG (OverseerAutoScalingTriggerThread-72144876451921926-127.0.0.1:46549_solr-n_0000000000) [ ] o.a.s.c.a.OverseerTriggerThread Adding .auto_add_replicas and .scheduled_maintenance triggers
[junit4] 2> 738609 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch fired: children: /solr/live_nodes
[junit4] 2> 738609 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch fired: children: /solr/live_nodes
[junit4] 2> 738610 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: data: /solr/autoscaling.json
[junit4] 2> 738610 DEBUG (OverseerAutoScalingTriggerThread-72144876451921926-127.0.0.1:46549_solr-n_0000000000) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 1
[junit4] 2> 738610 DEBUG (OverseerAutoScalingTriggerThread-72144876451921926-127.0.0.1:46549_solr-n_0000000000) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 1, lastZnodeVersion -1
[junit4] 2> 738610 DEBUG (OverseerAutoScalingTriggerThread-72144876451921926-127.0.0.1:46549_solr-n_0000000000) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 1
[junit4] 2> 738615 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: children: /solr/live_nodes
[junit4] 2> 738616 INFO (zkCallback-2549-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 738616 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: children: /solr/live_nodes
[junit4] 2> 738616 INFO (zkCallback-2542-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 738617 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: children: /solr/autoscaling/events/.scheduled_maintenance
[junit4] 2> 738618 INFO (jetty-launcher-2526-thread-2) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:38105/solr
[junit4] 2> 738619 DEBUG (OverseerAutoScalingTriggerThread-72144876451921926-127.0.0.1:46549_solr-n_0000000000) [ ] o.a.s.c.a.NodeLostTrigger NodeLostTrigger .auto_add_replicas - Initial livenodes: [127.0.0.1:46549_solr]
[junit4] 2> 738621 DEBUG (OverseerAutoScalingTriggerThread-72144876451921926-127.0.0.1:46549_solr-n_0000000000) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers
[junit4] 2> 738621 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: children: /solr/autoscaling/events/.auto_add_replicas
[junit4] 2> 738621 DEBUG (ScheduledTrigger-5775-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 738621 DEBUG (OverseerAutoScalingTriggerThread-72144876451921926-127.0.0.1:46549_solr-n_0000000000) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 1, lastZnodeVersion 1
[junit4] 2> 738622 INFO (jetty-launcher-2526-thread-1) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:38105/solr
[junit4] 2> 738626 INFO (zkConnectionManagerCallback-2555-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 738633 DEBUG (jetty-launcher-2526-thread-2) [n:127.0.0.1:40385_solr ] o.a.s.c.ZkController Added new OnReconnect listener org.apache.solr.cloud.ZkController$$Lambda$45/1631193300@31136be7
[junit4] 2> 738636 INFO (zkConnectionManagerCallback-2558-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 738637 INFO (jetty-launcher-2526-thread-4) [n:127.0.0.1:46549_solr ] o.a.s.h.a.MetricsHistoryHandler No .system collection, keeping metrics history in memory.
[junit4] 2> 738637 INFO (zkConnectionManagerCallback-2561-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 738637 DEBUG (jetty-launcher-2526-thread-1) [n:127.0.0.1:39343_solr ] o.a.s.c.ZkController Added new OnReconnect listener org.apache.solr.cloud.ZkController$$Lambda$45/1631193300@11471035
[junit4] 2> 738639 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: create/delete: /solr/clusterprops.json
[junit4] 2> 738639 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: children: /solr/live_nodes
[junit4] 2> 738639 INFO (jetty-launcher-2526-thread-2) [n:127.0.0.1:40385_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 738639 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: data: /solr/clusterstate.json
[junit4] 2> 738639 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: children: /solr/collections
[junit4] 2> 738640 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: create/delete: /solr/aliases.json
[junit4] 2> 738640 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: create/delete: /solr/security.json
[junit4] 2> 738640 DEBUG (jetty-launcher-2526-thread-2) [n:127.0.0.1:40385_solr ] o.a.s.c.LeaderElector Joined leadership election with path: /overseer_elect/election/72144876451921930-127.0.0.1:40385_solr-n_0000000001
[junit4] 2> 738640 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: data: /solr/overseer_elect/election/72144876451921926-127.0.0.1:46549_solr-n_0000000000
[junit4] 2> 738640 DEBUG (jetty-launcher-2526-thread-2) [n:127.0.0.1:40385_solr ] o.a.s.c.LeaderElector Watching path /overseer_elect/election/72144876451921926-127.0.0.1:46549_solr-n_0000000000 to know if I could be the leader
[junit4] 2> 738640 DEBUG (jetty-launcher-2526-thread-2) [n:127.0.0.1:40385_solr ] o.a.s.c.ZkController Publish node=127.0.0.1:40385_solr as DOWN
[junit4] 2> 738641 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch fired: children: /solr/overseer/queue
[junit4] 2> 738641 INFO (jetty-launcher-2526-thread-2) [n:127.0.0.1:40385_solr ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores
[junit4] 2> 738641 INFO (jetty-launcher-2526-thread-2) [n:127.0.0.1:40385_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:40385_solr
[junit4] 2> 738641 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch fired: children: /solr/live_nodes
[junit4] 2> 738641 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch fired: children: /solr/live_nodes
[junit4] 2> 738641 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch fired: children: /solr/live_nodes
[junit4] 2> 738645 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: children: /solr/live_nodes
[junit4] 2> 738646 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: children: /solr/overseer/queue
[junit4] 2> 738646 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: children: /solr/live_nodes
[junit4] 2> 738646 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: children: /solr/live_nodes
[junit4] 2> 738646 INFO (zkCallback-2560-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
[junit4] 2> 738646 INFO (zkCallback-2542-thread-2) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
[junit4] 2> 738646 DEBUG (OverseerStateUpdate-72144876451921926-127.0.0.1:46549_solr-n_0000000000) [ ] o.a.s.c.Overseer processMessage: queueSize: 1, message = {
[junit4] 2> "operation":"downnode",
[junit4] 2> "node_name":"127.0.0.1:40385_solr"} current state version: 0
[junit4] 2> 738646 DEBUG (OverseerStateUpdate-72144876451921926-127.0.0.1:46549_solr-n_0000000000) [ ] o.a.s.c.o.NodeMutator DownNode state invoked for node: 127.0.0.1:40385_solr
[junit4] 2> 738649 INFO (zkCallback-2549-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
[junit4] 2> 738649 INFO (zkConnectionManagerCallback-2563-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 738653 INFO (jetty-launcher-2526-thread-4) [n:127.0.0.1:46549_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_46549.solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@7b4950aa
[junit4] 2> 738653 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: create/delete: /solr/clusterprops.json
[junit4] 2> 738654 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: children: /solr/live_nodes
[junit4] 2> 738654 INFO (jetty-launcher-2526-thread-1) [n:127.0.0.1:39343_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (2)
[junit4] 2> 738654 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: data: /solr/clusterstate.json
[junit4] 2> 738654 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: children: /solr/collections
[junit4] 2> 738654 INFO (zkConnectionManagerCallback-2573-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 738654 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: create/delete: /solr/aliases.json
[junit4] 2> 738654 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: create/delete: /solr/clusterprops.json
[junit4] 2> 738655 INFO (jetty-launcher-2526-thread-3) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:38105/solr
[junit4] 2> 738655 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: create/delete: /solr/security.json
[junit4] 2> 738655 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: children: /solr/live_nodes
[junit4] 2> 738655 INFO (jetty-launcher-2526-thread-2) [n:127.0.0.1:40385_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (2)
[junit4] 2> 738655 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: data: /solr/clusterstate.json
[junit4] 2> 738656 INFO (zkConnectionManagerCallback-2576-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 738656 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: children: /solr/collections
[junit4] 2> 738656 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: create/delete: /solr/aliases.json
[junit4] 2> 738656 DEBUG (jetty-launcher-2526-thread-1) [n:127.0.0.1:39343_solr ] o.a.s.c.LeaderElector Joined leadership election with path: /overseer_elect/election/72144876451921931-127.0.0.1:39343_solr-n_0000000002
[junit4] 2> 738656 INFO (jetty-launcher-2526-thread-2) [n:127.0.0.1:40385_solr ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:38105/solr ready
[junit4] 2> 738656 INFO (jetty-launcher-2526-thread-2) [n:127.0.0.1:40385_solr ] o.a.s.h.a.MetricsHistoryHandler No .system collection, keeping metrics history in memory.
[junit4] 2> 738656 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: data: /solr/overseer_elect/election/72144876451921930-127.0.0.1:40385_solr-n_0000000001
[junit4] 2> 738656 DEBUG (jetty-launcher-2526-thread-1) [n:127.0.0.1:39343_solr ] o.a.s.c.LeaderElector Watching path /overseer_elect/election/72144876451921930-127.0.0.1:40385_solr-n_0000000001 to know if I could be the leader
[junit4] 2> 738656 DEBUG (jetty-launcher-2526-thread-1) [n:127.0.0.1:39343_solr ] o.a.s.c.ZkController Publish node=127.0.0.1:39343_solr as DOWN
[junit4] 2> 738657 DEBUG (jetty-launcher-2526-thread-3) [n:127.0.0.1:46639_solr ] o.a.s.c.ZkController Added new OnReconnect listener org.apache.solr.cloud.ZkController$$Lambda$45/1631193300@64ab698b
[junit4] 2> 738657 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch fired: children: /solr/overseer/queue
[junit4] 2> 738657 INFO (jetty-launcher-2526-thread-1) [n:127.0.0.1:39343_solr ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores
[junit4] 2> 738657 INFO (jetty-launcher-2526-thread-1) [n:127.0.0.1:39343_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:39343_solr
[junit4] 2> 738657 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: children: /solr/overseer/queue
[junit4] 2> 738658 DEBUG (OverseerStateUpdate-72144876451921926-127.0.0.1:46549_solr-n_0000000000) [ ] o.a.s.c.Overseer processMessage: queueSize: 2, message = {
[junit4] 2> "operation":"downnode",
[junit4] 2> "node_name":"127.0.0.1:39343_solr"} current state version: 0
[junit4] 2> 738658 DEBUG (OverseerStateUpdate-72144876451921926-127.0.0.1:46549_solr-n_0000000000) [ ] o.a.s.c.o.NodeMutator DownNode state invoked for node: 127.0.0.1:39343_solr
[junit4] 2> 738658 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch fired: children: /solr/live_nodes
[junit4] 2> 738658 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch fired: children: /solr/live_nodes
[junit4] 2> 738658 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch fired: children: /solr/live_nodes
[junit4] 2> 738658 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch fired: children: /solr/live_nodes
[junit4] 2> 738658 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch fired: children: /solr/live_nodes
[junit4] 2> 738658 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: children: /solr/live_nodes
[junit4] 2> 738658 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: children: /solr/live_nodes
[junit4] 2> 738658 INFO (zkCallback-2542-thread-2) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3)
[junit4] 2> 738658 INFO (zkCallback-2549-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3)
[junit4] 2> 738668 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: children: /solr/live_nodes
[junit4] 2> 738668 INFO (zkConnectionManagerCallback-2579-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 738668 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: children: /solr/live_nodes
[junit4] 2> 738668 INFO (zkCallback-2560-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3)
[junit4] 2> 738668 INFO (jetty-launcher-2526-thread-4) [n:127.0.0.1:46549_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_46549.solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@7b4950aa
[junit4] 2> 738668 INFO (zkCallback-2562-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3)
[junit4] 2> 738668 INFO (jetty-launcher-2526-thread-4) [n:127.0.0.1:46549_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_46549.solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@7b4950aa
[junit4] 2> 738669 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: children: /solr/live_nodes
[junit4] 2> 738669 INFO (zkCallback-2572-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3)
[junit4] 2> 738669 INFO (jetty-launcher-2526-thread-4) [n:127.0.0.1:46549_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /home/jenkins/workspace/Lucene-Solr-7.x-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.AddReplicaTest_600A05C720F9336C-001/tempDir-001/node4/.
[junit4] 2> 738671 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: create/delete: /solr/clusterprops.json
[junit4] 2> 738671 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: children: /solr/live_nodes
[junit4] 2> 738671 INFO (jetty-launcher-2526-thread-3) [n:127.0.0.1:46639_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (3)
[junit4] 2> 738671 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: data: /solr/clusterstate.json
[junit4] 2> 738671 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: children: /solr/collections
[junit4] 2> 738671 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: create/delete: /solr/aliases.json
[junit4] 2> 738672 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: create/delete: /solr/security.json
[junit4] 2> 738672 DEBUG (jetty-launcher-2526-thread-3) [n:127.0.0.1:46639_solr ] o.a.s.c.LeaderElector Joined leadership election with path: /overseer_elect/election/72144876451921934-127.0.0.1:46639_solr-n_0000000003
[junit4] 2> 738673 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: data: /solr/overseer_elect/election/72144876451921931-127.0.0.1:39343_solr-n_0000000002
[junit4] 2> 738673 DEBUG (jetty-launcher-2526-thread-3) [n:127.0.0.1:46639_solr ] o.a.s.c.LeaderElector Watching path /overseer_elect/election/72144876451921931-127.0.0.1:39343_solr-n_0000000002 to know if I could be the leader
[junit4] 2> 738673 DEBUG (jetty-launcher-2526-thread-3) [n:127.0.0.1:46639_solr ] o.a.s.c.ZkController Publish node=127.0.0.1:46639_solr as DOWN
[junit4] 2> 738673 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch fired: children: /solr/overseer/queue
[junit4] 2> 738673 INFO (jetty-launcher-2526-thread-3) [n:127.0.0.1:46639_solr ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores
[junit4] 2> 738673 INFO (jetty-launcher-2526-thread-3) [n:127.0.0.1:46639_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:46639_solr
[junit4] 2> 738673 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: children: /solr/overseer/queue
[junit4] 2> 738673 DEBUG (OverseerStateUpdate-72144876451921926-127.0.0.1:46549_solr-n_0000000000) [ ] o.a.s.c.Overseer processMessage: queueSize: 3, message = {
[junit4] 2> "operation":"downnode",
[junit4] 2> "node_name":"127.0.0.1:46639_solr"} current state version: 0
[junit4] 2> 738673 DEBUG (OverseerStateUpdate-72144876451921926-127.0.0.1:46549_solr-n_0000000000) [ ] o.a.s.c.o.NodeMutator DownNode state invoked for node: 127.0.0.1:46639_solr
[junit4] 2> 738673 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch fired: children: /solr/live_nodes
[junit4] 2> 738673 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch fired: children: /solr/live_nodes
[junit4] 2> 738673 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch fired: children: /solr/live_nodes
[junit4] 2> 738673 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch fired: children: /solr/live_nodes
[junit4] 2> 738674 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch fired: children: /solr/live_nodes
[junit4] 2> 738674 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch fired: children: /solr/live_nodes
[junit4] 2> 738674 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: children: /solr/live_nodes
[junit4] 2> 738674 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: children: /solr/live_nodes
[junit4] 2> 738674 INFO (zkCallback-2549-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4)
[junit4] 2> 738674 INFO (zkCallback-2572-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4)
[junit4] 2> 738674 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: children: /solr/live_nodes
[junit4] 2> 738674 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: children: /solr/live_nodes
[junit4] 2> 738674 INFO (zkCallback-2542-thread-2) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4)
[junit4] 2> 738674 INFO (zkCallback-2560-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4)
[junit4] 2> 738676 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: children: /solr/live_nodes
[junit4] 2> 738676 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: children: /solr/live_nodes
[junit4] 2> 738676 INFO (zkCallback-2562-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4)
[junit4] 2> 738677 INFO (zkCallback-2578-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4)
[junit4] 2> 738677 INFO (jetty-launcher-2526-thread-2) [n:127.0.0.1:40385_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_40385.solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@7b4950aa
[junit4] 2> 738679 INFO (zkConnectionManagerCallback-2586-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 738680 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: create/delete: /solr/clusterprops.json
[junit4] 2> 738680 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: children: /solr/live_nodes
[junit4] 2> 738680 INFO (jetty-launcher-2526-thread-1) [n:127.0.0.1:39343_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (4)
[junit4] 2> 738680 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: data: /solr/clusterstate.json
[junit4] 2> 738680 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: children: /solr/collections
[junit4] 2> 738680 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: create/delete: /solr/aliases.json
[junit4] 2> 738680 INFO (jetty-launcher-2526-thread-1) [n:127.0.0.1:39343_solr ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:38105/solr ready
[junit4] 2> 738681 INFO (jetty-launcher-2526-thread-1) [n:127.0.0.1:39343_solr ] o.a.s.h.a.MetricsHistoryHandler No .system collection, keeping metrics history in memory.
[junit4] 2> 738682 INFO (jetty-launcher-2526-thread-2) [n:127.0.0.1:40385_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_40385.solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@7b4950aa
[junit4] 2> 738682 INFO (jetty-launcher-2526-thread-2) [n:127.0.0.1:40385_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_40385.solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@7b4950aa
[junit4] 2> 738683 INFO (jetty-launcher-2526-thread-2) [n:127.0.0.1:40385_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /home/jenkins/workspace/Lucene-Solr-7.x-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.AddReplicaTest_600A05C720F9336C-001/tempDir-001/node2/.
[junit4] 2> 738686 INFO (zkConnectionManagerCallback-2592-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 738686 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: create/delete: /solr/clusterprops.json
[junit4] 2> 738686 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: children: /solr/live_nodes
[junit4] 2> 738686 INFO (jetty-launcher-2526-thread-3) [n:127.0.0.1:46639_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (4)
[junit4] 2> 738686 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: data: /solr/clusterstate.json
[junit4] 2> 738687 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: children: /solr/collections
[junit4] 2> 738687 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: create/delete: /solr/aliases.json
[junit4] 2> 738687 INFO (jetty-launcher-2526-thread-3) [n:127.0.0.1:46639_solr ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:38105/solr ready
[junit4] 2> 738687 INFO (jetty-launcher-2526-thread-3) [n:127.0.0.1:46639_solr ] o.a.s.h.a.MetricsHistoryHandler No .system collection, keeping metrics history in memory.
[junit4] 2> 738696 INFO (jetty-launcher-2526-thread-1) [n:127.0.0.1:39343_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_39343.solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@7b4950aa
[junit4] 2> 738697 INFO (jetty-launcher-2526-thread-3) [n:127.0.0.1:46639_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_46639.solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@7b4950aa
[junit4] 2> 738702 INFO (jetty-launcher-2526-thread-3) [n:127.0.0.1:46639_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_46639.solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@7b4950aa
[junit4] 2> 738702 INFO (jetty-launcher-2526-thread-3) [n:127.0.0.1:46639_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_46639.solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@7b4950aa
[junit4] 2> 738703 INFO (jetty-launcher-2526-thread-3) [n:127.0.0.1:46639_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /home/jenkins/workspace/Lucene-Solr-7.x-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.AddReplicaTest_600A05C720F9336C-001/tempDir-001/node3/.
[junit4] 2> 738704 INFO (jetty-launcher-2526-thread-1) [n:127.0.0.1:39343_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_39343.solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@7b4950aa
[junit4] 2> 738704 INFO (jetty-launcher-2526-thread-1) [n:127.0.0.1:39343_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_39343.solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@7b4950aa
[junit4] 2> 738705 INFO (jetty-launcher-2526-thread-1) [n:127.0.0.1:39343_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /home/jenkins/workspace/Lucene-Solr-7.x-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.AddReplicaTest_600A05C720F9336C-001/tempDir-001/node1/.
[junit4] 2> 738741 INFO (zkConnectionManagerCallback-2595-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 738746 INFO (zkConnectionManagerCallback-2600-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 738746 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: create/delete: /solr/clusterprops.json
[junit4] 2> 738747 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: children: /solr/live_nodes
[junit4] 2> 738747 INFO (SUITE-AddReplicaTest-seed#[600A05C720F9336C]-worker) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (4)
[junit4] 2> 738747 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: data: /solr/clusterstate.json
[junit4] 2> 738747 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: children: /solr/collections
[junit4] 2> 738747 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: create/delete: /solr/aliases.json
[junit4] 2> 738747 INFO (SUITE-AddReplicaTest-seed#[600A05C720F9336C]-worker) [ ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:38105/solr ready
[junit4] 2> 738769 INFO (TEST-AddReplicaTest.test-seed#[600A05C720F9336C]) [ ] o.a.s.SolrTestCaseJ4 ###Starting test
[junit4] 2> 738770 INFO (zkConnectionManagerCallback-2602-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 738772 INFO (qtp1203952686-12581) [n:127.0.0.1:40385_solr ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :create with params collection.configName=conf1&maxShardsPerNode=2&name=addreplicatest_coll&nrtReplicas=1&action=CREATE&numShards=2&wt=javabin&version=2 and sendToOCPQueue=true
[junit4] 2> 738773 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch fired: children: /solr/overseer/collection-queue-work
[junit4] 2> 738773 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: create/delete: /solr/overseer/collection-queue-work/qnr-0000000000
[junit4] 2> 738773 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: children: /solr/overseer/collection-queue-work
[junit4] 2> 738773 DEBUG (OverseerCollectionConfigSetProcessor-72144876451921926-127.0.0.1:46549_solr-n_0000000000) [ ] o.a.s.c.ZkDistributedQueue Found child node with improper name: qnr-0000000000
[junit4] 2> 738773 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch fired: children: /solr/overseer/collection-queue-work
[junit4] 2> 738773 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: children: /solr/overseer/collection-queue-work
[junit4] 2> 738773 DEBUG (OverseerCollectionConfigSetProcessor-72144876451921926-127.0.0.1:46549_solr-n_0000000000) [ ] o.a.s.c.ZkDistributedQueue Found child node with improper name: qnr-0000000000
[junit4] 2> 738773 DEBUG (OverseerCollectionConfigSetProcessor-72144876451921926-127.0.0.1:46549_solr-n_0000000000) [ ] o.a.s.c.OverseerTaskQueue Returning topN elements: [/overseer/collection-queue-work/qn-0000000000, ]
[junit4] 2> 738773 DEBUG (OverseerCollectionConfigSetProcessor-72144876451921926-127.0.0.1:46549_solr-n_0000000000) [ ] o.a.s.c.OverseerTaskProcessor Got 1 tasks from work-queue : [[org.apache.solr.cloud.OverseerTaskQueue$QueueEvent@2e684ecf]]
[junit4] 2> 738773 DEBUG (OverseerCollectionConfigSetProcessor-72144876451921926-127.0.0.1:46549_solr-n_0000000000) [ ] o.a.s.c.OverseerTaskProcessor Marked task [/overseer/collection-queue-work/qn-0000000000] as running
[junit4] 2> 738773 DEBUG (OverseerCollectionConfigSetProcessor-72144876451921926-127.0.0.1:46549_solr-n_0000000000) [ ] o.a.s.c.OverseerTaskProcessor Overseer Collection Message Handler: Get the message id:/overseer/collection-queue-work/qn-0000000000 message:{
[junit4] 2> "name":"addreplicatest_coll",
[junit4] 2> "fromApi":"true",
[junit4] 2> "collection.configName":"conf1",
[junit4] 2> "numShards":"2",
[junit4] 2> "maxShardsPerNode":"2",
[junit4] 2> "nrtReplicas":"1",
[junit4] 2> "stateFormat":"2",
[junit4] 2> "replicationFactor":"1",
[junit4] 2> "operation":"create"}
[junit4] 2> 738774 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch fired: children: /solr/overseer/queue
[junit4] 2> 738774 DEBUG (OverseerThreadFactory-5779-thread-1) [ ] o.a.s.c.OverseerTaskProcessor Runner processing /overseer/collection-queue-work/qn-0000000000
[junit4] 2> 738774 DEBUG (OverseerThreadFactory-5779-thread-1) [ ] o.a.s.c.a.c.OverseerCollectionMessageHandler OverseerCollectionMessageHandler.processMessage : create , {
[junit4] 2> "name":"addreplicatest_coll",
[junit4] 2> "fromApi":"true",
[junit4] 2> "collection.configName":"conf1",
[junit4] 2> "numShards":"2",
[junit4] 2> "maxShardsPerNode":"2",
[junit4] 2> "nrtReplicas":"1",
[junit4] 2> "stateFormat":"2",
[junit4] 2> "replicationFactor":"1",
[junit4] 2> "operation":"create"}
[junit4] 2> 738774 DEBUG (OverseerCollectionConfigSetProcessor-72144876451921926-127.0.0.1:46549_solr-n_0000000000) [ ] o.a.s.c.OverseerTaskProcessor Cleaning up work-queue. #Running tasks: 1
[junit4] 2> 738774 INFO (OverseerThreadFactory-5779-thread-1) [ ] o.a.s.c.a.c.CreateCollectionCmd Create collection addreplicatest_coll
[junit4] 2> 738774 DEBUG (OverseerCollectionConfigSetProcessor-72144876451921926-127.0.0.1:46549_solr-n_0000000000) [ ] o.a.s.c.OverseerTaskProcessor RunningTasks: [/overseer/collection-queue-work/qn-0000000000]
[junit4] 2> 738774 DEBUG (OverseerCollectionConfigSetProcessor-72144876451921926-127.0.0.1:46549_solr-n_0000000000) [ ] o.a.s.c.OverseerTaskProcessor BlockedTasks: []
[junit4] 2> 738774 DEBUG (OverseerCollectionConfigSetProcessor-72144876451921926-127.0.0.1:46549_solr-n_0000000000) [ ] o.a.s.c.OverseerTaskProcessor CompletedTasks: []
[junit4] 2> 738774 DEBUG (OverseerCollectionConfigSetProcessor-72144876451921926-127.0.0.1:46549_solr-n_0000000000) [ ] o.a.s.c.OverseerTaskProcessor RunningZKTasks: [/overseer/collection-queue-work/qn-0000000000]
[junit4] 2> 738774 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: children: /solr/overseer/queue
[junit4] 2> 738774 DEBUG (OverseerCollectionConfigSetProcessor-72144876451921926-127.0.0.1:46549_solr-n_0000000000) [ ] o.a.s.c.OverseerTaskQueue Peeking for top 99 elements. ExcludeSet: [/overseer/collection-queue-work/qn-0000000000],[]
[junit4] 2> 738774 DEBUG (OverseerThreadFactory-5779-thread-1) [ ] o.a.s.c.a.c.OverseerCollectionMessageHandler creating collections conf node /collections/addreplicatest_coll
[junit4] 2> 738774 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch fired: children: /solr/collections
[junit4] 2> 738774 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch fired: children: /solr/collections
[junit4] 2> 738774 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch fired: children: /solr/collections
[junit4] 2> 738774 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch fired: children: /solr/collections
[junit4] 2> 738774 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch fired: children: /solr/collections
[junit4] 2> 738774 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch fired: children: /solr/collections
[junit4] 2> 738774 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch fired: children: /solr/collections
[junit4] 2> 738774 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch fired: children: /solr/collections
[junit4] 2> 738774 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch fired: children: /solr/collections
[junit4] 2> 738775 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: children: /solr/collections
[junit4] 2> 738775 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: children: /solr/collections
[junit4] 2> 738775 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: children: /solr/collections
[junit4] 2> 738775 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: children: /solr/collections
[junit4] 2> 738775 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: children: /solr/collections
[junit4] 2> 738775 DEBUG (OverseerThreadFactory-5779-thread-1) [ ] o.a.s.c.a.c.CreateCollectionCmd Check for collection zkNode:addreplicatest_coll
[junit4] 2> 738775 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: children: /solr/collections
[junit4] 2> 738775 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: children: /solr/collections
[junit4] 2> 738775 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: children: /solr/collections
[junit4] 2> 738775 DEBUG (OverseerThreadFactory-5779-thread-1) [ ] o.a.s.c.a.c.CreateCollectionCmd Collection zkNode exists
[junit4] 2> 738775 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: children: /solr/collections
[junit4] 2> 738775 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch fired: children: /solr/overseer/queue
[junit4] 2> 738775 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: children: /solr/overseer/queue
[junit4] 2> 738775 DEBUG (OverseerStateUpdate-72144876451921926-127.0.0.1:46549_solr-n_0000000000) [ ] o.a.s.c.Overseer processMessage: queueSize: 1, message = {
[junit4] 2> "name":"addreplicatest_coll",
[junit4] 2> "fromApi":"true",
[junit4] 2> "collection.configName":"conf1",
[junit4] 2> "numShards":"2",
[junit4] 2> "maxShardsPerNode":"2",
[junit4] 2> "nrtReplicas":"1",
[junit4] 2> "stateFormat":"2",
[junit4] 2> "replicationFactor":"1",
[junit4] 2> "operation":"create"} current state version: 0
[junit4] 2> 738775 DEBUG (OverseerStateUpdate-72144876451921926-127.0.0.1:46549_solr-n_0000000000) [ ] o.a.s.c.o.ClusterStateMutator building a new cName: addreplicatest_coll
[junit4] 2> 738776 DEBUG (OverseerStateUpdate-72144876451921926-127.0.0.1:46549_solr-n_0000000000) [ ] o.a.s.c.o.ZkStateWriter going to create_collection /collections/addreplicatest_coll/state.json
[junit4] 2> 738776 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch fired: children: /solr/overseer/queue
[junit4] 2> 738776 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: children: /solr/overseer/queue
[junit4] 2> 738876 DEBUG (OverseerThreadFactory-5779-thread-1) [ ] o.a.s.c.a.c.Assign Identify nodes using default
[junit4] 2> 738876 DEBUG (OverseerThreadFactory-5779-thread-1) [ ] o.a.s.c.a.c.CreateCollectionCmd Creating SolrCores for new collection addreplicatest_coll, shardNames [shard1, shard2] , message : {
[junit4] 2> "name":"addreplicatest_coll",
[junit4] 2> "fromApi":"true",
[junit4] 2> "collection.configName":"conf1",
[junit4] 2> "numShards":"2",
[junit4] 2> "maxShardsPerNode":"2",
[junit4] 2> "nrtReplicas":"1",
[junit4] 2> "stateFormat":"2",
[junit4] 2> "replicationFactor":"1",
[junit4] 2> "operation":"create"}
[junit4] 2> 738877 DEBUG (OverseerThreadFactory-5779-thread-1) [ ] o.a.s.c.a.c.CreateCollectionCmd Creating core addreplicatest_coll_shard1_replica_n1 as part of shard shard1 of collection addreplicatest_coll on 127.0.0.1:40385_solr
[junit4] 2> 738877 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch fired: children: /solr/overseer/queue
[junit4] 2> 738878 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: children: /solr/overseer/queue
[junit4] 2> 738878 DEBUG (OverseerStateUpdate-72144876451921926-127.0.0.1:46549_solr-n_0000000000) [ ] o.a.s.c.Overseer processMessage: queueSize: 1, message = {
[junit4] 2> "operation":"ADDREPLICA",
[junit4] 2> "collection":"addreplicatest_coll",
[junit4] 2> "shard":"shard1",
[junit4] 2> "core":"addreplicatest_coll_shard1_replica_n1",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"http://127.0.0.1:40385/solr",
[junit4] 2> "type":"NRT",
[junit4] 2> "waitForFinalState":"false"} current state version: 0
[junit4] 2> 738878 INFO (OverseerStateUpdate-72144876451921926-127.0.0.1:46549_solr-n_0000000000) [ ] o.a.s.c.o.SliceMutator createReplica() {
[junit4] 2> "operation":"ADDREPLICA",
[junit4] 2> "collection":"addreplicatest_coll",
[junit4] 2> "shard":"shard1",
[junit4] 2> "core":"addreplicatest_coll_shard1_replica_n1",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"http://127.0.0.1:40385/solr",
[junit4] 2> "type":"NRT",
[junit4] 2> "waitForFinalState":"false"}
[junit4] 2> 738878 DEBUG (OverseerThreadFactory-5779-thread-1) [ ] o.a.s.c.a.c.CreateCollectionCmd Creating core addreplicatest_coll_shard2_replica_n2 as part of shard shard2 of collection addreplicatest_coll on 127.0.0.1:46639_solr
[junit4] 2> 738879 DEBUG (OverseerStateUpdate-72144876451921926-127.0.0.1:46549_solr-n_0000000000) [ ] o.a.s.c.o.SliceMutator Old Slice: shard1:{
[junit4] 2> "range":"80000000-ffffffff",
[junit4] 2> "state":"active",
[junit4] 2> "replicas":{}}
[junit4] 2> 738879 DEBUG (OverseerStateUpdate-72144876451921926-127.0.0.1:46549_solr-n_0000000000) [ ] o.a.s.c.o.SliceMutator New Slice: shard1:{
[junit4] 2> "range":"80000000-ffffffff",
[junit4] 2> "state":"active",
[junit4] 2> "replicas":{"core_node3":{
[junit4] 2> "core":"addreplicatest_coll_shard1_replica_n1",
[junit4] 2> "base_url":"http://127.0.0.1:40385/solr",
[junit4] 2> "state":"down",
[junit4] 2> "node_name":null,
[junit4] 2> "type":"NRT"}}}
[junit4] 2> 738879 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch fired: children: /solr/overseer/queue
[junit4] 2> 738879 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: children: /solr/overseer/queue
[junit4] 2> 738879 DEBUG (OverseerThreadFactory-5779-thread-1) [ ] o.a.s.c.a.c.OverseerCollectionMessageHandler Expecting [addreplicatest_coll_shard1_replica_n1, addreplicatest_coll_shard2_replica_n2] cores but found {}
[junit4] 2> 738879 DEBUG (OverseerStateUpdate-72144876451921926-127.0.0.1:46549_solr-n_0000000000) [ ] o.a.s.c.Overseer processMessage: queueSize: 2, message = {
[junit4] 2> "operation":"ADDREPLICA",
[junit4] 2> "collection":"addreplicatest_coll",
[junit4] 2> "shard":"shard2",
[junit4] 2> "core":"addreplicatest_coll_shard2_replica_n2",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"http://127.0.0.1:46639/solr",
[junit4] 2> "type":"NRT",
[junit4] 2> "waitForFinalState":"false"} current state version: 0
[junit4] 2> 738880 INFO (OverseerStateUpdate-72144876451921926-127.0.0.1:46549_solr-n_0000000000) [ ] o.a.s.c.o.SliceMutator createReplica() {
[junit4] 2> "operation":"ADDREPLICA",
[junit4] 2> "collection":"addreplicatest_coll",
[junit4] 2> "shard":"shard2",
[junit4] 2> "core":"addreplicatest_coll_shard2_replica_n2",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"http://127.0.0.1:46639/solr",
[junit4] 2> "type":"NRT",
[junit4] 2> "waitForFinalState":"false"}
[junit4] 2> 738880 DEBUG (OverseerStateUpdate-72144876451921926-127.0.0.1:46549_solr-n_0000000000) [ ] o.a.s.c.o.SliceMutator Old Slice: shard2:{
[junit4] 2> "range":"0-7fffffff",
[junit4] 2> "state":"active",
[junit4] 2> "replicas":{}}
[junit4] 2> 738880 DEBUG (OverseerStateUpdate-72144876451921926-127.0.0.1:46549_solr-n_0000000000) [ ] o.a.s.c.o.SliceMutator New Slice: shard2:{
[junit4] 2> "range":"0-7fffffff",
[junit4] 2> "state":"active",
[junit4] 2> "replicas":{"core_node4":{
[junit4] 2> "core":"addreplicatest_coll_shard2_replica_n2",
[junit4] 2> "base_url":"http://127.0.0.1:46639/solr",
[junit4] 2> "state":"down",
[junit4] 2> "node_name":null,
[junit4] 2> "type":"NRT"}}}
[junit4] 2> 738980 DEBUG (OverseerThreadFactory-5779-thread-1) [ ] o.a.s.c.a.c.OverseerCollectionMessageHandler Expecting [addreplicatest_coll_shard1_replica_n1, addreplicatest_coll_shard2_replica_n2] cores but found {}
[junit4] 2> 738980 DEBUG (OverseerStateUpdate-72144876451921926-127.0.0.1:46549_solr-n_0000000000) [ ] o.a.s.c.o.ZkStateWriter going to update_collection /collections/addreplicatest_coll/state.json version: 0
[junit4] 2> 738981 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch fired: children: /solr/overseer/queue
[junit4] 2> 738981 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: children: /solr/overseer/queue
[junit4] 2> 739083 INFO (qtp1694454132-12599) [n:127.0.0.1:46639_solr x:addreplicatest_coll_shard2_replica_n2] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&coreNodeName=core_node4&collection.configName=conf1&newCollection=true&name=addreplicatest_coll_shard2_replica_n2&action=CREATE&numShards=2&collection=addreplicatest_coll&shard=shard2&wt=javabin&version=2&replicaType=NRT
[junit4] 2> 739083 INFO (qtp1203952686-12572) [n:127.0.0.1:40385_solr x:addreplicatest_coll_shard1_replica_n1] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&coreNodeName=core_node3&collection.configName=conf1&newCollection=true&name=addreplicatest_coll_shard1_replica_n1&action=CREATE&numShards=2&collection=addreplicatest_coll&shard=shard1&wt=javabin&version=2&replicaType=NRT
[junit4] 2> 739083 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: data: /solr/collections/addreplicatest_coll/state.json
[junit4] 2> 739084 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: data: /solr/collections/addreplicatest_coll/state.json
[junit4] 2> 739084 DEBUG (qtp1694454132-12599) [n:127.0.0.1:46639_solr c:addreplicatest_coll s:shard2 r:core_node4 x:addreplicatest_coll_shard2_replica_n2] o.a.s.c.ZkController publishing state=down
[junit4] 2> 739084 DEBUG (qtp1203952686-12572) [n:127.0.0.1:40385_solr c:addreplicatest_coll s:shard1 r:core_node3 x:addreplicatest_coll_shard1_replica_n1] o.a.s.c.ZkController publishing state=down
[junit4] 2> 739084 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch fired: children: /solr/overseer/queue
[junit4] 2> 739084 DEBUG (qtp1694454132-12599) [n:127.0.0.1:46639_solr c:addreplicatest_coll s:shard2 r:core_node4 x:addreplicatest_coll_shard2_replica_n2] o.a.s.c.ZkController Registering watch for collection addreplicatest_coll
[junit4] 2> 739084 DEBUG (qtp1203952686-12572) [n:127.0.0.1:40385_solr c:addreplicatest_coll s:shard1 r:core_node3 x:addreplicatest_coll_shard1_replica_n1] o.a.s.c.ZkController Registering watch for collection addreplicatest_coll
[junit4] 2> 739084 DEBUG (qtp1694454132-12599) [n:127.0.0.1:46639_solr c:addreplicatest_coll s:shard2 r:core_node4 x:addreplicatest_coll_shard2_replica_n2] o.a.s.c.ZkController waiting to find shard id in clusterstate for addreplicatest_coll_shard2_replica_n2
[junit4] 2> 739084 DEBUG (qtp1203952686-12572) [n:127.0.0.1:40385_solr c:addreplicatest_coll s:shard1 r:core_node3 x:addreplicatest_coll_shard1_replica_n1] o.a.s.c.ZkController waiting to find shard id in clusterstate for addreplicatest_coll_shard1_replica_n1
[junit4] 2> 739084 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: children: /solr/overseer/queue
[junit4] 2> 739084 DEBUG (OverseerStateUpdate-72144876451921926-127.0.0.1:46549_solr-n_0000000000) [ ] o.a.s.c.Overseer processMessage: queueSize: 2, message = {
[junit4] 2> "core":"addreplicatest_coll_shard2_replica_n2",
[junit4] 2> "core_node_name":"core_node4",
[junit4] 2> "roles":null,
[junit4] 2> "base_url":"http://127.0.0.1:46639/solr",
[junit4] 2> "node_name":"127.0.0.1:46639_solr",
[junit4] 2> "numShards":"2",
[junit4] 2> "state":"down",
[junit4] 2> "shard":"shard2",
[junit4] 2> "collection":"addreplicatest_coll",
[junit4] 2> "type":"NRT",
[junit4] 2> "force_set_state":"false",
[junit4] 2> "operation":"state"} current state version: 0
[junit4] 2> 739085 DEBUG (OverseerStateUpdate-72144876451921926-127.0.0.1:46549_solr-n_0000000000) [ ] o.a.s.c.o.ReplicaMutator Update state numShards=2 message={
[junit4] 2> "core":"addreplicatest_coll_shard2_replica_n2",
[junit4] 2> "core_node_name":"core_node4",
[junit4] 2> "roles":null,
[junit4] 2> "base_url":"http://127.0.0.1:46639/solr",
[junit4] 2> "node_name":"127.0.0.1:46639_solr",
[junit4] 2> "numShards":"2",
[junit4] 2> "state":"down",
[junit4] 2> "shard":"shard2",
[junit4] 2> "collection":"addreplicatest_coll",
[junit4] 2> "type":"NRT",
[junit4] 2> "force_set_state":"false",
[junit4] 2> "operation":"state"}
[junit4] 2> 739085 DEBUG (OverseerStateUpdate-72144876451921926-127.0.0.1:46549_solr-n_0000000000) [ ] o.a.s.c.o.ReplicaMutator Will update state for replica: core_node4:{"core":"addreplicatest_coll_shard2_replica_n2","base_url":"http://127.0.0.1:46639/solr","node_name":"127.0.0.1:46639_solr","state":"down","type":"NRT","force_set_state":"false"}
[junit4] 2> 739085 DEBUG (OverseerStateUpdate-72144876451921926-127.0.0.1:46549_solr-n_0000000000) [ ] o.a.s.c.o.ReplicaMutator Collection is now: DocCollection(addreplicatest_coll//collections/addreplicatest_coll/state.json/1)={
[junit4] 2> "pullReplicas":"0",
[junit4] 2> "replicationFactor":"1",
[junit4] 2> "router":{"name":"compositeId"},
[junit4] 2> "maxShardsPerNode":"2",
[junit4] 2> "autoAddReplicas":"false",
[junit4] 2> "nrtReplicas":"1",
[junit4] 2> "tlogReplicas":"0",
[junit4] 2> "shards":{
[junit4] 2> "shard1":{
[junit4] 2> "range":"80000000-ffffffff",
[junit4] 2> "state":"active",
[junit4] 2> "replicas":{"core_node3":{
[junit4] 2> "core":"addreplicatest_coll_shard1_replica_n1",
[junit4] 2> "base_url":"http://127.0.0.1:40385/solr",
[junit4] 2> "state":"down",
[junit4] 2> "node_name":null,
[junit4] 2> "type":"NRT"}}},
[junit4] 2> "shard2":{
[junit4] 2> "range":"0-7fffffff",
[junit4] 2> "state":"active",
[junit4] 2> "replicas":{"core_node4":{
[junit4] 2> "core":"addreplicatest_coll_shard2_replica_n2",
[junit4] 2> "base_url":"http://127.0.0.1:46639/solr",
[junit4] 2> "node_name":"127.0.0.1:46639_solr",
[junit4] 2> "state":"down",
[junit4] 2> "type":"NRT",
[junit4] 2> "force_set_state":"false"}}}}}
[junit4] 2> 739085 DEBUG (OverseerStateUpdate-72144876451921926-127.0.0.1:46549_solr-n_0000000000) [ ] o.a.s.c.Overseer processMessage: queueSize: 2, message = {
[junit4] 2> "core":"addreplicatest_coll_shard1_replica_n1",
[junit4] 2> "core_node_name":"core_node3",
[junit4] 2> "roles":null,
[junit4] 2> "base_url":"http://127.0.0.1:40385/solr",
[junit4] 2> "node_name":"127.0.0.1:40385_solr",
[junit4] 2> "numShards":"2",
[junit4] 2> "state":"down",
[junit4] 2> "shard":"shard1",
[junit4] 2> "collection":"addreplicatest_coll",
[junit4] 2> "type":"NRT",
[junit4] 2> "force_set_state":"false",
[junit4] 2> "operation":"state"} current state version: 0
[junit4] 2> 739085 DEBUG (OverseerStateUpdate-72144876451921926-127.0.0.1:46549_solr-n_0000000000) [ ] o.a.s.c.o.ReplicaMutator Update state numShards=2 message={
[junit4] 2> "core":"addreplicatest_coll_shard1_replica_n1",
[junit4] 2> "core_node_name":"core_node3",
[junit4] 2> "roles":null,
[junit4] 2> "base_url":"http://127.0.0.1:40385/solr",
[junit4] 2> "node_name":"127.0.0.1:40385_solr",
[junit4] 2> "numShards":"2",
[junit4] 2> "state":"down",
[junit4] 2> "shard":"shard1",
[junit4] 2> "collection":"addreplicatest_coll",
[junit4] 2> "type":"NRT",
[junit4] 2> "force_set_state":"false",
[junit4] 2> "operation":"state"}
[junit4] 2> 739085 DEBUG (OverseerStateUpdate-72144876451921926-127.0.0.1:46549_solr-n_0000000000) [ ] o.a.s.c.o.ReplicaMutator Will update state for replica: core_node3:{"core":"addreplicatest_coll_shard1_replica_n1","base_url":"http://127.0.0.1:40385/solr","node_name":"127.0.0.1:40385_solr","state":"down","type":"NRT","force_set_state":"false"}
[junit4] 2> 739085 DEBUG (OverseerStateUpdate-72144876451921926-127.0.0.1:46549_solr-n_0000000000) [ ] o.a.s.c.o.ReplicaMutator Collection is now: DocCollection(addreplicatest_coll//collections/addreplicatest_coll/state.json/1)={
[junit4] 2> "pullReplicas":"0",
[junit4] 2> "replicationFactor":"1",
[junit4] 2> "router":{"name":"compositeId"},
[junit4] 2> "maxShardsPerNode":"2",
[junit4] 2> "autoAddReplicas":"false",
[junit4] 2> "nrtReplicas":"1",
[junit4] 2> "tlogReplicas":"0",
[junit4] 2> "shards":{
[junit4] 2> "shard1":{
[junit4] 2> "range":"80000000-ffffffff",
[junit4] 2> "state":"active",
[junit4] 2> "replicas":{"core_node3":{
[junit4] 2> "core":"addreplicatest_coll_shard1_replica_n1",
[junit4] 2> "base_url":"http://127.0.0.1:40385/solr",
[junit4] 2> "node_name":"127.0.0.1:40385_solr",
[junit4] 2> "state":"down",
[junit4] 2> "type":"NRT",
[junit4] 2> "force_set_state":"false"}}},
[junit4] 2> "shard2":{
[junit4] 2> "range":"0-7fffffff",
[junit4] 2> "state":"active",
[junit4] 2> "replicas":{"core_node4":{
[junit4] 2> "core":"addreplicatest_coll_shard2_replica_n2",
[junit4] 2> "base_url":"http://127.0.0.1:46639/solr",
[junit4] 2> "node_name":"127.0.0.1:46639_solr",
[junit4] 2> "state":"down",
[junit4] 2> "type":"NRT",
[junit4] 2> "force_set_state":"false"}}}}}
[junit4] 2> 739185 DEBUG (OverseerStateUpdate-72144876451921926-127.0.0.1:46549_solr-n_0000000000) [ ] o.a.s.c.o.ZkStateWriter going to update_collection /collections/addreplicatest_coll/state.json version: 1
[junit4] 2> 739186 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch fired: data: /solr/collections/addreplicatest_coll/state.json
[junit4] 2> 739186 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch fired: data: /solr/collections/addreplicatest_coll/state.json
[junit4] 2> 739186 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch fired: children: /solr/overseer/queue
[junit4] 2> 739186 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: children: /solr/overseer/queue
[junit4] 2> 739623 DEBUG (ScheduledTrigger-5775-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 4
[junit4] 2> 740090 INFO (qtp1203952686-12572) [n:127.0.0.1:40385_solr c:addreplicatest_coll s:shard1 r:core_node3 x:addreplicatest_coll_shard1_replica_n1] o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.5.0
[junit4] 2> 740090 INFO (qtp1694454132-12599) [n:127.0.0.1:46639_solr c:addreplicatest_coll s:shard2 r:core_node4 x:addreplicatest_coll_shard2_replica_n2] o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.5.0
[junit4] 2> 740108 INFO (qtp1694454132-12599) [n:127.0.0.1:46639_solr c:addreplicatest_coll s:shard2 r:core_node4 x:addreplicatest_coll_shard2_replica_n2] o.a.s.s.IndexSchema [addreplicatest_coll_shard2_replica_n2] Schema name=minimal
[junit4] 2> 740108 INFO (qtp1203952686-12572) [n:127.0.0.1:40385_solr c:addreplicatest_coll s:shard1 r:core_node3 x:addreplicatest_coll_shard1_replica_n1] o.a.s.s.IndexSchema [addreplicatest_coll_shard1_replica_n1] Schema name=minimal
[junit4] 2> 740110 INFO (qtp1203952686-12572) [n:127.0.0.1:40385_solr c:addreplicatest_coll s:shard1 r:core_node3 x:addreplicatest_coll_shard1_replica_n1] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
[junit4] 2> 740110 INFO (qtp1694454132-12599) [n:127.0.0.1:46639_solr c:addreplicatest_coll s:shard2 r:core_node4 x:addreplicatest_coll_shard2_replica_n2] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
[junit4] 2> 740110 INFO (qtp1694454132-12599) [n:127.0.0.1:46639_solr c:addreplicatest_coll s:shard2 r:core_node4 x:addreplicatest_coll_shard2_replica_n2] o.a.s.c.CoreContainer Creating SolrCore 'addreplicatest_coll_shard2_replica_n2' using configuration from collection addreplicatest_coll, trusted=true
[junit4] 2> 740110 INFO (qtp1203952686-12572) [n:127.0.0.1:40385_solr c:addreplicatest_coll s:shard1 r:core_node3 x:addreplicatest_coll_shard1_replica_n1] o.a.s.c.CoreContainer Creating SolrCore 'addreplicatest_coll_shard1_replica_n1' using configuration from collection addreplicatest_coll, trusted=true
[junit4] 2> 740110 INFO (qtp1203952686-12572) [n:127.0.0.1:40385_solr c:addreplicatest_coll s:shard1 r:core_node3 x:addreplicatest_coll_shard1_replica_n1] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_40385.solr.core.addreplicatest_coll.shard1.replica_n1' (registry 'solr.core.addreplicatest_coll.shard1.replica_n1') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@7b4950aa
[junit4] 2> 740110 INFO (qtp1694454132-12599) [n:127.0.0.1:46639_solr c:addreplicatest_coll s:shard2 r:core_node4 x:addreplicatest_coll_shard2_replica_n2] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_46639.solr.core.addreplicatest_coll.shard2.replica_n2' (registry 'solr.core.addreplicatest_coll.shard2.replica_n2') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@7b4950aa
[junit4] 2> 740110 INFO (qtp1203952686-12572) [n:127.0.0.1:40385_solr c:addreplicatest_coll s:shard1 r:core_node3 x:addreplicatest_coll_shard1_replica_n1] o.a.s.c.SolrCore solr.RecoveryStrategy.Builder
[junit4] 2> 740110 INFO (qtp1694454132-12599) [n:127.0.0.1:46639_solr c:addreplicatest_coll s:shard2 r:core_node4 x:addreplicatest_coll_shard2_replica_n2] o.a.s.c.SolrCore solr.RecoveryStrategy.Builder
[junit4] 2> 740110 INFO (qtp1203952686-12572) [n:127.0.0.1:40385_solr c:addreplicatest_coll s:shard1 r:core_node3 x:addreplicatest_coll_shard1_replica_n1] o.a.s.c.SolrCore [[addreplicatest_coll_shard1_replica_n1] ] Opening new SolrCore at [/home/jenkins/workspace/Lucene-Solr-7.x-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.AddReplicaTest_600A05C720F9336C-001/tempDir-001/node2/addreplicatest_coll_shard1_replica_n1], dataDir=[/home/jenkins/workspace/Lucene-Solr-7.x-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.AddReplicaTest_600A05C720F9336C-001/tempDir-001/node2/./addreplicatest_coll_shard1_replica_n1/data/]
[junit4] 2> 740110 INFO (qtp1694454132-12599) [n:127.0.0.1:46639_solr c:addreplicatest_coll s:shard2 r:core_node4 x:addreplicatest_coll_shard2_replica_n2] o.a.s.c.SolrCore [[addreplicatest_coll_shard2_replica_n2] ] Opening new SolrCore at [/home/jenkins/workspace/Lucene-Solr-7.x-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.AddReplicaTest_600A05C720F9336C-001/tempDir-001/node3/addreplicatest_coll_shard2_replica_n2], dataDir=[/home/jenkins/workspace/Lucene-Solr-7.x-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.AddReplicaTest_600A05C720F9336C-001/tempDir-001/node3/./addreplicatest_coll_shard2_replica_n2/data/]
[junit4] 2> 740139 INFO (qtp1203952686-12572) [n:127.0.0.1:40385_solr c:addreplicatest_coll s:shard1 r:core_node3 x:addreplicatest_coll_shard1_replica_n1] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
[junit4] 2> 740139 INFO (qtp1694454132-12599) [n:127.0.0.1:46639_solr c:addreplicatest_coll s:shard2 r:core_node4 x:addreplicatest_coll_shard2_replica_n2] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
[junit4] 2> 740139 INFO (qtp1203952686-12572) [n:127.0.0.1:40385_solr c:addreplicatest_coll s:shard1 r:core_node3 x:addreplicatest_coll_shard1_replica_n1] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 740139 INFO (qtp1694454132-12599) [n:127.0.0.1:46639_solr c:addreplicatest_coll s:shard2 r:core_node4 x:addreplicatest_coll_shard2_replica_n2] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 740140 INFO (qtp1203952686-12572) [n:127.0.0.1:40385_solr c:addreplicatest_coll s:shard1 r:core_node3 x:addreplicatest_coll_shard1_replica_n1] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 740140 INFO (qtp1694454132-12599) [n:127.0.0.1:46639_solr c:addreplicatest_coll s:shard2 r:core_node4 x:addreplicatest_coll_shard2_replica_n2] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 740140 INFO (qtp1203952686-12572) [n:127.0.0.1:40385_solr c:addreplicatest_coll s:shard1 r:core_node3 x:addreplicatest_coll_shard1_replica_n1] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 740140 INFO (qtp1694454132-12599) [n:127.0.0.1:46639_solr c:addreplicatest_coll s:shard2 r:core_node4 x:addreplicatest_coll_shard2_replica_n2] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 740140 INFO (qtp1203952686-12572) [n:127.0.0.1:40385_solr c:addreplicatest_coll s:shard1 r:core_node3 x:addreplicatest_coll_shard1_replica_n1] o.a.s.s.SolrIndexSearcher Opening [Searcher@33f56500[addreplicatest_coll_shard1_replica_n1] main]
[junit4] 2> 740140 INFO (qtp1694454132-12599) [n:127.0.0.1:46639_solr c:addreplicatest_coll s:shard2 r:core_node4 x:addreplicatest_coll_shard2_replica_n2] o.a.s.s.SolrIndexSearcher Opening [Searcher@f7fb349[addreplicatest_coll_shard2_replica_n2] main]
[junit4] 2> 740141 INFO (qtp1694454132-12599) [n:127.0.0.1:46639_solr c:addreplicatest_coll s:shard2 r:core_node4 x:addreplicatest_coll_shard2_replica_n2] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf1
[junit4] 2> 740141 INFO (qtp1203952686-12572) [n:127.0.0.1:40385_solr c:addreplicatest_coll s:shard1 r:core_node3 x:addreplicatest_coll_shard1_replica_n1] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf1
[junit4] 2> 740141 INFO (qtp1203952686-12572) [n:127.0.0.1:40385_solr c:addreplicatest_coll s:shard1 r:core_node3 x:addreplicatest_coll_shard1_replica_n1] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
[junit4] 2> 740141 INFO (qtp1694454132-12599) [n:127.0.0.1:46639_solr c:addreplicatest_coll s:shard2 r:core_node4 x:addreplicatest_coll_shard2_replica_n2] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
[junit4] 2> 740142 INFO (qtp1203952686-12572) [n:127.0.0.1:40385_solr c:addreplicatest_coll s:shard1 r:core_node3 x:addreplicatest_coll_shard1_replica_n1] o.a.s.h.ReplicationHandler Commits will be reserved for 10000ms.
[junit4] 2> 740142 INFO (qtp1694454132-12599) [n:127.0.0.1:46639_solr c:addreplicatest_coll s:shard2 r:core_node4 x:addreplicatest_coll_shard2_replica_n2] o.a.s.h.ReplicationHandler Commits will be reserved for 10000ms.
[junit4] 2> 740142 INFO (qtp1694454132-12599) [n:127.0.0.1:46639_solr c:addreplicatest_coll s:shard2 r:core_node4 x:addreplicatest_coll_shard2_replica_n2] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1608546559825281024
[junit4] 2> 740142 INFO (searcherExecutor-5803-thread-1-processing-n:127.0.0.1:40385_solr x:addreplicatest_coll_shard1_replica_n1 c:addreplicatest_coll s:shard1 r:core_node3) [n:127.0.0.1:40385_solr c:addreplicatest_coll s:shard1 r:core_node3 x:addreplicatest_coll_shard1_replica_n1] o.a.s.c.SolrCore [addreplicatest_coll_shard1_replica_n1] Registered new searcher Searcher@33f56500[addreplicatest_coll_shard1_replica_n1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 740142 INFO (searcherExecutor-5802-thread-1-processing-n:127.0.0.1:46639_solr x:addreplicatest_coll_shard2_replica_n2 c:addreplicatest_coll s:shard2 r:core_node4) [n:127.0.0.1:46639_solr c:addreplicatest_coll s:shard2 r:core_node4 x:addreplicatest_coll_shard2_replica_n2] o.a.s.c.SolrCore [addreplicatest_coll_shard2_replica_n2] Registered new searcher Searcher@f7fb349[addreplicatest_coll_shard2_replica_n2] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 740142 INFO (qtp1203952686-12572) [n:127.0.0.1:40385_solr c:addreplicatest_coll s:shard1 r:core_node3 x:addreplicatest_coll_shard1_replica_n1] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1608546559825281024
[junit4] 2> 740143 DEBUG (qtp1694454132-12599) [n:127.0.0.1:46639_solr c:addreplicatest_coll s:shard2 r:core_node4 x:addreplicatest_coll_shard2_replica_n2] o.a.s.c.ZkController watch zkdir /configs/conf1
[junit4] 2> 740143 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: create/delete: /solr/configs/conf1
[junit4] 2> 740143 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: data: /solr/collections/addreplicatest_coll/state.json
[junit4] 2> 740143 DEBUG (qtp1203952686-12572) [n:127.0.0.1:40385_solr c:addreplicatest_coll s:shard1 r:core_node3 x:addreplicatest_coll_shard1_replica_n1] o.a.s.c.ZkController watch zkdir /configs/conf1
[junit4] 2> 740143 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: create/delete: /solr/configs/conf1
[junit4] 2> 740144 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: data: /solr/collections/addreplicatest_coll/state.json
[junit4] 2> 740144 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: create/delete: /solr/collections/addreplicatest_coll/terms/shard1
[junit4] 2> 740144 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: create/delete: /solr/collections/addreplicatest_coll/terms/shard2
[junit4] 2> 740144 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch fired: data: /solr/collections/addreplicatest_coll/terms/shard1
[junit4] 2> 740145 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch fired: data: /solr/collections/addreplicatest_coll/terms/shard2
[junit4] 2> 740145 INFO (qtp1203952686-12572) [n:127.0.0.1:40385_solr c:addreplicatest_coll s:shard1 r:core_node3 x:addreplicatest_coll_shard1_replica_n1] o.a.s.c.ZkShardTerms Successful update of terms at /collections/addreplicatest_coll/terms/shard1 to Terms{values={core_node3=0}, version=0}
[junit4] 2> 740145 DEBUG (qtp1203952686-12572) [n:127.0.0.1:40385_solr c:addreplicatest_coll s:shard1 r:core_node3 x:addreplicatest_coll_shard1_replica_n1] o.a.s.c.ZkController Register replica - core:addreplicatest_coll_shard1_replica_n1 address:http://127.0.0.1:40385/solr collection:addreplicatest_coll shard:shard1
[junit4] 2> 740145 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: create/delete: /solr/collections/addreplicatest_coll/terms/shard1
[junit4] 2> 740145 INFO (qtp1694454132-12599) [n:127.0.0.1:46639_solr c:addreplicatest_coll s:shard2 r:core_node4 x:addreplicatest_coll_shard2_replica_n2] o.a.s.c.ZkShardTerms Successful update of terms at /collections/addreplicatest_coll/terms/shard2 to Terms{values={core_node4=0}, version=0}
[junit4] 2> 740145 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: create/delete: /solr/collections/addreplicatest_coll/terms/shard2
[junit4] 2> 740145 DEBUG (qtp1694454132-12599) [n:127.0.0.1:46639_solr c:addreplicatest_coll s:shard2 r:core_node4 x:addreplicatest_coll_shard2_replica_n2] o.a.s.c.ZkController Register replica - core:addreplicatest_coll_shard2_replica_n2 address:http://127.0.0.1:46639/solr collection:addreplicatest_coll shard:shard2
[junit4] 2> 740145 DEBUG (qtp1203952686-12572) [n:127.0.0.1:40385_solr c:addreplicatest_coll s:shard1 r:core_node3 x:addreplicatest_coll_shard1_replica_n1] o.a.s.c.LeaderElector Joined leadership election with path: /collections/addreplicatest_coll/leader_elect/shard1/election/72144876451921930-core_node3-n_0000000000
[junit4] 2> 740145 DEBUG (qtp1694454132-12599) [n:127.0.0.1:46639_solr c:addreplicatest_coll s:shard2 r:core_node4 x:addreplicatest_coll_shard2_replica_n2] o.a.s.c.LeaderElector Joined leadership election with path: /collections/addreplicatest_coll/leader_elect/shard2/election/72144876451921934-core_node4-n_0000000000
[junit4] 2> 740145 DEBUG (qtp1203952686-12572) [n:127.0.0.1:40385_solr c:addreplicatest_coll s:shard1 r:core_node3 x:addreplicatest_coll_shard1_replica_n1] o.a.s.c.ShardLeaderElectionContext Running the leader process for shard=shard1 and weAreReplacement=false and leaderVoteWait=10000
[junit4] 2> 740146 DEBUG (qtp1694454132-12599) [n:127.0.0.1:46639_solr c:addreplicatest_coll s:shard2 r:core_node4 x:addreplicatest_coll_shard2_replica_n2] o.a.s.c.ShardLeaderElectionContext Running the leader process for shard=shard2 and weAreReplacement=false and leaderVoteWait=10000
[junit4] 2> 740146 INFO (qtp1203952686-12572) [n:127.0.0.1:40385_solr c:addreplicatest_coll s:shard1 r:core_node3 x:addreplicatest_coll_shard1_replica_n1] o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue.
[junit4] 2> 740146 INFO (qtp1203952686-12572) [n:127.0.0.1:40385_solr c:addreplicatest_coll s:shard1 r:core_node3 x:addreplicatest_coll_shard1_replica_n1] o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync
[junit4] 2> 740146 INFO (qtp1203952686-12572) [n:127.0.0.1:40385_solr c:addreplicatest_coll s:shard1 r:core_node3 x:addreplicatest_coll_shard1_replica_n1] o.a.s.c.SyncStrategy Sync replicas to http://127.0.0.1:40385/solr/addreplicatest_coll_shard1_replica_n1/
[junit4] 2> 740146 INFO (qtp1694454132-12599) [n:127.0.0.1:46639_solr c:addreplicatest_coll s:shard2 r:core_node4 x:addreplicatest_coll_shard2_replica_n2] o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue.
[junit4] 2> 740146 INFO (qtp1694454132-12599) [n:127.0.0.1:46639_solr c:addreplicatest_coll s:shard2 r:core_node4 x:addreplicatest_coll_shard2_replica_n2] o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync
[junit4] 2> 740146 INFO (qtp1694454132-12599) [n:127.0.0.1:46639_solr c:addreplicatest_coll s:shard2 r:core_node4 x:addreplicatest_coll_shard2_replica_n2] o.a.s.c.SyncStrategy Sync replicas to http://127.0.0.1:46639/solr/addreplicatest_coll_shard2_replica_n2/
[junit4] 2> 740146 INFO (qtp1203952686-12572) [n:127.0.0.1:40385_solr c:addreplicatest_coll s:shard1 r:core_node3 x:addreplicatest_coll_shard1_replica_n1] o.a.s.c.SyncStrategy Sync Success - now sync replicas to me
[junit4] 2> 740146 INFO (qtp1694454132-12599) [n:127
[...truncated too long message...]
nfigure:
[ivy:configure] :: loading settings :: file = /home/jenkins/workspace/Lucene-Solr-7.x-Linux/lucene/top-level-ivy-settings.xml
resolve:
init:
-clover.disable:
-clover.load:
-clover.classpath:
-clover.setup:
clover:
compile-core:
init:
-clover.disable:
-clover.load:
-clover.classpath:
-clover.setup:
clover:
common.compile-core:
[javac] Compiling 3 source files to /home/jenkins/workspace/Lucene-Solr-7.x-Linux/solr/build/solr-core/classes/java
common-solr.compile-core:
compile-core:
compile-test-framework:
-check-git-state:
-git-cleanroot:
-copy-git-state:
git-autoclean:
ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.
-ivy-fail-disallowed-ivy-version:
ivy-fail:
ivy-configure:
[ivy:configure] :: loading settings :: file = /home/jenkins/workspace/Lucene-Solr-7.x-Linux/lucene/top-level-ivy-settings.xml
resolve:
init:
compile-lucene-core:
compile-codecs:
-check-git-state:
-git-cleanroot:
-copy-git-state:
git-autoclean:
ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.
-ivy-fail-disallowed-ivy-version:
ivy-fail:
ivy-configure:
[ivy:configure] :: loading settings :: file = /home/jenkins/workspace/Lucene-Solr-7.x-Linux/lucene/top-level-ivy-settings.xml
resolve:
common.init:
compile-lucene-core:
init:
-clover.disable:
-clover.load:
-clover.classpath:
-clover.setup:
clover:
compile-core:
-clover.disable:
-clover.load:
-clover.classpath:
-clover.setup:
clover:
common.compile-core:
compile-core:
common.compile-test:
[mkdir] Created dir: /home/jenkins/workspace/Lucene-Solr-7.x-Linux/solr/build/solr-core/classes/test
[javac] Compiling 926 source files to /home/jenkins/workspace/Lucene-Solr-7.x-Linux/solr/build/solr-core/classes/test
[javac] Note: Some input files use or override a deprecated API.
[javac] Note: Recompile with -Xlint:deprecation for details.
[javac] Note: Some input files use unchecked or unsafe operations.
[javac] Note: Recompile with -Xlint:unchecked for details.
[javac] Creating empty /home/jenkins/workspace/Lucene-Solr-7.x-Linux/solr/build/solr-core/classes/test/org/apache/solr/cloud/autoscaling/sim/package-info.class
[copy] Copying 1 file to /home/jenkins/workspace/Lucene-Solr-7.x-Linux/solr/build/solr-core/classes/test
common-solr.compile-test:
compile-test:
BUILD SUCCESSFUL
Total time: 1 minute 4 seconds
[repro] ant test-nocompile -Dtests.dups=5 -Dtests.maxfailures=5 -Dtests.class="*.AddReplicaTest" -Dtests.showOutput=onerror "-Dargs=-XX:-UseCompressedOops -XX:+UseSerialGC" -Dtests.seed=600A05C720F9336C -Dtests.multiplier=3 -Dtests.slow=true -Dtests.locale=he -Dtests.timezone=America/Santo_Domingo -Dtests.asserts=true -Dtests.file.encoding=UTF-8
Buildfile: /home/jenkins/workspace/Lucene-Solr-7.x-Linux/solr/core/build.xml
-clover.disable:
ivy-configure:
[ivy:configure] :: Apache Ivy 2.4.0 - 20141213170938 :: http://ant.apache.org/ivy/ ::
[ivy:configure] :: loading settings :: file = /home/jenkins/workspace/Lucene-Solr-7.x-Linux/lucene/top-level-ivy-settings.xml
install-junit4-taskdef:
ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.
-ivy-fail-disallowed-ivy-version:
ivy-fail:
resolve-groovy:
[ivy:cachepath] :: resolving dependencies :: org.codehaus.groovy#groovy-all-caller;working
[ivy:cachepath] confs: [default]
[ivy:cachepath] found org.codehaus.groovy#groovy-all;2.4.15 in public
[ivy:cachepath] :: resolution report :: resolve 21ms :: artifacts dl 0ms
---------------------------------------------------------------------
| | modules || artifacts |
| conf | number| search|dwnlded|evicted|| number|dwnlded|
---------------------------------------------------------------------
| default | 1 | 0 | 0 | 0 || 1 | 0 |
---------------------------------------------------------------------
-init-totals:
-test:
[mkdir] Created dir: /home/jenkins/workspace/Lucene-Solr-7.x-Linux/solr/build/solr-core/test
[junit4:pickseed] Seed property 'tests.seed' already defined: 600A05C720F9336C
[mkdir] Created dir: /home/jenkins/workspace/Lucene-Solr-7.x-Linux/solr/build/solr-core/test/temp
[junit4] <JUnit4> says ahoj! Master seed: 600A05C720F9336C
[junit4] Executing 5 suites with 3 JVMs.
[junit4]
[junit4] Started J0 PID(5119@serv1.sd-datasolutions.de).
[junit4] Started J1 PID(5121@serv1.sd-datasolutions.de).
[junit4] Started J2 PID(5120@serv1.sd-datasolutions.de).
[junit4] Suite: org.apache.solr.cloud.AddReplicaTest
[junit4] OK 10.1s J0 | AddReplicaTest.test
[junit4] Completed [1/5] on J0 in 19.08s, 1 test
[junit4]
[junit4] Suite: org.apache.solr.cloud.AddReplicaTest
[junit4] OK 10.3s J2 | AddReplicaTest.test
[junit4] Completed [2/5] on J2 in 20.69s, 1 test
[junit4]
[junit4] Duplicate suite name used with XML reports: org.apache.solr.cloud.AddReplicaTest. This may confuse tools that process XML reports. Set 'ignoreDuplicateSuites' to true to skip this message.
[junit4] Suite: org.apache.solr.cloud.AddReplicaTest
[junit4] OK 11.6s J1 | AddReplicaTest.test
[junit4] Completed [3/5] on J1 in 22.40s, 1 test
[junit4]
[junit4] Suite: org.apache.solr.cloud.AddReplicaTest
[junit4] OK 7.31s J0 | AddReplicaTest.test
[junit4] Completed [4/5] on J0 in 9.12s, 1 test
[junit4]
[junit4] Suite: org.apache.solr.cloud.AddReplicaTest
[junit4] OK 7.15s J2 | AddReplicaTest.test
[junit4] Completed [5/5] on J2 in 9.13s, 1 test
[junit4]
[junit4] JVM J0: 0.66 .. 30.16 = 29.50s
[junit4] JVM J1: 0.66 .. 24.06 = 23.40s
[junit4] JVM J2: 0.66 .. 31.95 = 31.29s
[junit4] Execution time total: 32 seconds
[junit4] Tests summary: 5 suites, 5 tests
[junit4] Could not remove temporary path: /home/jenkins/workspace/Lucene-Solr-7.x-Linux/solr/build/solr-core/test/J1 (java.nio.file.DirectoryNotEmptyException: Remaining files: [/home/jenkins/workspace/Lucene-Solr-7.x-Linux/solr/build/solr-core/test/J1/temp])
[junit4] Could not remove temporary path: /home/jenkins/workspace/Lucene-Solr-7.x-Linux/solr/build/solr-core/test/J2 (java.nio.file.DirectoryNotEmptyException: Remaining files: [/home/jenkins/workspace/Lucene-Solr-7.x-Linux/solr/build/solr-core/test/J2/temp])
[junit4] Could not remove temporary path: /home/jenkins/workspace/Lucene-Solr-7.x-Linux/solr/build/solr-core/test/J0 (java.nio.file.DirectoryNotEmptyException: Remaining files: [/home/jenkins/workspace/Lucene-Solr-7.x-Linux/solr/build/solr-core/test/J0/temp])
[echo] 5 slowest tests:
[junit4:tophints] 116.61s | org.apache.solr.update.SoftAutoCommitTest
[junit4:tophints] 113.28s | org.apache.solr.cloud.ZkFailoverTest
[junit4:tophints] 111.54s | org.apache.solr.cloud.DeleteReplicaTest
[junit4:tophints] 105.53s | org.apache.solr.cloud.TestTlogReplica
[junit4:tophints] 102.73s | org.apache.solr.cloud.TestWithCollection
-check-totals:
test-nocompile:
BUILD SUCCESSFUL
Total time: 34 seconds
[repro] Failures:
[repro] 0/5 failed: org.apache.solr.cloud.AddReplicaTest
[repro] Exiting with code 0
+ mv lucene/build lucene/build.repro
+ mv solr/build solr/build.repro
+ mv lucene/build.orig lucene/build
+ mv solr/build.orig solr/build
Archiving artifacts
Setting ANT_1_8_2_HOME=/var/lib/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2
java.lang.InterruptedException: no matches found within 10000
at hudson.FilePath$ValidateAntFileMask.hasMatch(FilePath.java:2845)
at hudson.FilePath$ValidateAntFileMask.invoke(FilePath.java:2724)
at hudson.FilePath$ValidateAntFileMask.invoke(FilePath.java:2705)
at hudson.FilePath.act(FilePath.java:1076)
at hudson.FilePath.act(FilePath.java:1059)
at hudson.FilePath.validateAntFileMask(FilePath.java:2703)
at hudson.tasks.ArtifactArchiver.perform(ArtifactArchiver.java:243)
at hudson.tasks.BuildStepCompatibilityLayer.perform(BuildStepCompatibilityLayer.java:81)
at hudson.tasks.BuildStepMonitor$1.perform(BuildStepMonitor.java:20)
at hudson.model.AbstractBuild$AbstractBuildExecution.perform(AbstractBuild.java:744)
at hudson.model.AbstractBuild$AbstractBuildExecution.performAllBuildSteps(AbstractBuild.java:690)
at hudson.model.Build$BuildExecution.post2(Build.java:186)
at hudson.model.AbstractBuild$AbstractBuildExecution.post(AbstractBuild.java:635)
at hudson.model.Run.execute(Run.java:1840)
at hudson.model.FreeStyleBuild.run(FreeStyleBuild.java:43)
at hudson.model.ResourceController.execute(ResourceController.java:97)
at hudson.model.Executor.run(Executor.java:429)
No artifacts found that match the file pattern "**/*.events,heapdumps/**,**/*_pid*.log". Configuration error?
[WARNINGS] Parsing warnings in console log with parser Java Compiler (javac)
Setting ANT_1_8_2_HOME=/var/lib/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2
Setting ANT_1_8_2_HOME=/var/lib/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2
<Git Blamer> Using GitBlamer to create author and commit information for all warnings.
<Git Blamer> GIT_COMMIT=6759ba7290304de397f7bcb7ad353feadcebacbb, workspace=/var/lib/jenkins/workspace/Lucene-Solr-7.x-Linux
[WARNINGS] Computing warning deltas based on reference build #2536
Recording test results
Setting ANT_1_8_2_HOME=/var/lib/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2
Build step 'Publish JUnit test result report' changed build result to UNSTABLE
Email was triggered for: Unstable (Test Failures)
Sending email for trigger: Unstable (Test Failures)
Setting ANT_1_8_2_HOME=/var/lib/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2
Setting ANT_1_8_2_HOME=/var/lib/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2
Setting ANT_1_8_2_HOME=/var/lib/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2
Setting ANT_1_8_2_HOME=/var/lib/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2