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/01/17 05:12:04 UTC
[JENKINS] Lucene-Solr-7.x-Linux (32bit/jdk1.8.0_144) - Build # 1190
- Still unstable!
Build: https://jenkins.thetaphi.de/job/Lucene-Solr-7.x-Linux/1190/
Java: 32bit/jdk1.8.0_144 -client -XX:+UseConcMarkSweepGC
1 tests failed.
FAILED: org.apache.solr.cloud.api.collections.CollectionsAPIDistributedZkTest.testCollectionsAPI
Error Message:
Error from server at https://127.0.0.1:43399/solr/awhollynewcollection_0_shard2_replica_n2: ClusterState says we are the leader (https://127.0.0.1:43399/solr/awhollynewcollection_0_shard2_replica_n2), 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 https://127.0.0.1:43399/solr/awhollynewcollection_0_shard2_replica_n2: ClusterState says we are the leader (https://127.0.0.1:43399/solr/awhollynewcollection_0_shard2_replica_n2), but locally we don't think so. Request came from null
at __randomizedtesting.SeedInfo.seed([1C0E541453B71943:547B20A0558436D6]:0)
at org.apache.solr.client.solrj.impl.CloudSolrClient.directUpdate(CloudSolrClient.java:550)
at org.apache.solr.client.solrj.impl.CloudSolrClient.sendRequest(CloudSolrClient.java:1013)
at org.apache.solr.client.solrj.impl.CloudSolrClient.requestWithRetryOnStaleState(CloudSolrClient.java:884)
at org.apache.solr.client.solrj.impl.CloudSolrClient.requestWithRetryOnStaleState(CloudSolrClient.java:946)
at org.apache.solr.client.solrj.impl.CloudSolrClient.requestWithRetryOnStaleState(CloudSolrClient.java:946)
at org.apache.solr.client.solrj.impl.CloudSolrClient.requestWithRetryOnStaleState(CloudSolrClient.java:946)
at org.apache.solr.client.solrj.impl.CloudSolrClient.requestWithRetryOnStaleState(CloudSolrClient.java:946)
at org.apache.solr.client.solrj.impl.CloudSolrClient.requestWithRetryOnStaleState(CloudSolrClient.java:946)
at org.apache.solr.client.solrj.impl.CloudSolrClient.request(CloudSolrClient.java:817)
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:462)
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)
Caused by: org.apache.solr.client.solrj.impl.HttpSolrClient$RemoteSolrException: Error from server at https://127.0.0.1:43399/solr/awhollynewcollection_0_shard2_replica_n2: ClusterState says we are the leader (https://127.0.0.1:43399/solr/awhollynewcollection_0_shard2_replica_n2), 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:527)
at java.util.concurrent.FutureTask.run(FutureTask.java:266)
at org.apache.solr.common.util.ExecutorUtil$MDCAwareThreadPoolExecutor.lambda$execute$0(ExecutorUtil.java:188)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
... 1 more
Build Log:
[...truncated 12441 lines...]
[junit4] Suite: org.apache.solr.cloud.api.collections.CollectionsAPIDistributedZkTest
[junit4] 2> 596724 INFO (SUITE-CollectionsAPIDistributedZkTest-seed#[1C0E541453B71943]-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/J1/temp/solr.cloud.api.collections.CollectionsAPIDistributedZkTest_1C0E541453B71943-001/init-core-data-001
[junit4] 2> 596725 WARN (SUITE-CollectionsAPIDistributedZkTest-seed#[1C0E541453B71943]-worker) [ ] o.a.s.SolrTestCaseJ4 startTrackingSearchers: numOpens=30 numCloses=30
[junit4] 2> 596726 INFO (SUITE-CollectionsAPIDistributedZkTest-seed#[1C0E541453B71943]-worker) [ ] o.a.s.SolrTestCaseJ4 Using PointFields (NUMERIC_POINTS_SYSPROP=true) w/NUMERIC_DOCVALUES_SYSPROP=false
[junit4] 2> 596729 INFO (SUITE-CollectionsAPIDistributedZkTest-seed#[1C0E541453B71943]-worker) [ ] o.a.s.SolrTestCaseJ4 Randomized ssl (true) and clientAuth (false) via: @org.apache.solr.util.RandomizeSSL(reason=, ssl=NaN, value=NaN, clientAuth=NaN)
[junit4] 2> 596732 INFO (SUITE-CollectionsAPIDistributedZkTest-seed#[1C0E541453B71943]-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/J1/temp/solr.cloud.api.collections.CollectionsAPIDistributedZkTest_1C0E541453B71943-001/tempDir-001
[junit4] 2> 596732 INFO (SUITE-CollectionsAPIDistributedZkTest-seed#[1C0E541453B71943]-worker) [ ] o.a.s.c.ZkTestServer STARTING ZK TEST SERVER
[junit4] 2> 596733 INFO (Thread-1293) [ ] o.a.s.c.ZkTestServer client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 596733 INFO (Thread-1293) [ ] o.a.s.c.ZkTestServer Starting server
[junit4] 2> 596735 ERROR (Thread-1293) [ ] 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> 596833 INFO (SUITE-CollectionsAPIDistributedZkTest-seed#[1C0E541453B71943]-worker) [ ] o.a.s.c.ZkTestServer start zk server on port:34027
[junit4] 2> 596845 INFO (zkConnectionManagerCallback-918-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 596916 INFO (jetty-launcher-915-thread-3) [ ] o.e.j.s.Server jetty-9.4.8.v20171121, build timestamp: 2017-11-22T05:27:37+08:00, git hash: 82b8fb23f757335bb3329d540ce37a2a2615f0a8
[junit4] 2> 596916 INFO (jetty-launcher-915-thread-4) [ ] o.e.j.s.Server jetty-9.4.8.v20171121, build timestamp: 2017-11-22T05:27:37+08:00, git hash: 82b8fb23f757335bb3329d540ce37a2a2615f0a8
[junit4] 2> 596917 INFO (jetty-launcher-915-thread-2) [ ] o.e.j.s.Server jetty-9.4.8.v20171121, build timestamp: 2017-11-22T05:27:37+08:00, git hash: 82b8fb23f757335bb3329d540ce37a2a2615f0a8
[junit4] 2> 596918 INFO (jetty-launcher-915-thread-1) [ ] o.e.j.s.Server jetty-9.4.8.v20171121, build timestamp: 2017-11-22T05:27:37+08:00, git hash: 82b8fb23f757335bb3329d540ce37a2a2615f0a8
[junit4] 2> 596925 INFO (jetty-launcher-915-thread-3) [ ] o.e.j.s.session DefaultSessionIdManager workerName=node0
[junit4] 2> 596925 INFO (jetty-launcher-915-thread-3) [ ] o.e.j.s.session No SessionScavenger set, using defaults
[junit4] 2> 596925 INFO (jetty-launcher-915-thread-3) [ ] o.e.j.s.session Scavenging every 660000ms
[junit4] 2> 596930 INFO (jetty-launcher-915-thread-4) [ ] o.e.j.s.session DefaultSessionIdManager workerName=node0
[junit4] 2> 596930 INFO (jetty-launcher-915-thread-4) [ ] o.e.j.s.session No SessionScavenger set, using defaults
[junit4] 2> 596930 INFO (jetty-launcher-915-thread-4) [ ] o.e.j.s.session Scavenging every 600000ms
[junit4] 2> 596931 INFO (jetty-launcher-915-thread-4) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@137cbc0{/solr,null,AVAILABLE}
[junit4] 2> 596933 INFO (jetty-launcher-915-thread-4) [ ] o.e.j.s.AbstractConnector Started ServerConnector@1311b76{SSL,[ssl, http/1.1]}{127.0.0.1:43399}
[junit4] 2> 596933 INFO (jetty-launcher-915-thread-4) [ ] o.e.j.s.Server Started @598718ms
[junit4] 2> 596933 INFO (jetty-launcher-915-thread-4) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=43399}
[junit4] 2> 596933 ERROR (jetty-launcher-915-thread-4) [ ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 596933 INFO (jetty-launcher-915-thread-4) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version 7.3.0
[junit4] 2> 596933 INFO (jetty-launcher-915-thread-4) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 596933 INFO (jetty-launcher-915-thread-4) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 596934 INFO (jetty-launcher-915-thread-4) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2018-01-17T04:03:40.303Z
[junit4] 2> 596938 INFO (jetty-launcher-915-thread-3) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@16bcfa{/solr,null,AVAILABLE}
[junit4] 2> 596939 INFO (jetty-launcher-915-thread-3) [ ] o.e.j.s.AbstractConnector Started ServerConnector@1422388{SSL,[ssl, http/1.1]}{127.0.0.1:33819}
[junit4] 2> 596939 INFO (jetty-launcher-915-thread-3) [ ] o.e.j.s.Server Started @598724ms
[junit4] 2> 596939 INFO (jetty-launcher-915-thread-3) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=33819}
[junit4] 2> 596939 ERROR (jetty-launcher-915-thread-3) [ ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 596939 INFO (jetty-launcher-915-thread-3) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version 7.3.0
[junit4] 2> 596939 INFO (jetty-launcher-915-thread-3) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 596939 INFO (jetty-launcher-915-thread-3) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 596939 INFO (jetty-launcher-915-thread-3) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2018-01-17T04:03:40.308Z
[junit4] 2> 596942 INFO (zkConnectionManagerCallback-922-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 596942 INFO (zkConnectionManagerCallback-920-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 596942 INFO (jetty-launcher-915-thread-2) [ ] o.e.j.s.session DefaultSessionIdManager workerName=node0
[junit4] 2> 596942 INFO (jetty-launcher-915-thread-2) [ ] o.e.j.s.session No SessionScavenger set, using defaults
[junit4] 2> 596943 INFO (jetty-launcher-915-thread-2) [ ] o.e.j.s.session Scavenging every 600000ms
[junit4] 2> 596943 INFO (jetty-launcher-915-thread-4) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 596943 INFO (jetty-launcher-915-thread-3) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 596955 INFO (jetty-launcher-915-thread-1) [ ] o.e.j.s.session DefaultSessionIdManager workerName=node0
[junit4] 2> 596955 INFO (jetty-launcher-915-thread-1) [ ] o.e.j.s.session No SessionScavenger set, using defaults
[junit4] 2> 596955 INFO (jetty-launcher-915-thread-1) [ ] o.e.j.s.session Scavenging every 660000ms
[junit4] 2> 596955 INFO (jetty-launcher-915-thread-2) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@1b6a7e{/solr,null,AVAILABLE}
[junit4] 2> 596955 INFO (jetty-launcher-915-thread-1) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@48eff2{/solr,null,AVAILABLE}
[junit4] 2> 596956 INFO (jetty-launcher-915-thread-2) [ ] o.e.j.s.AbstractConnector Started ServerConnector@1733f7b{SSL,[ssl, http/1.1]}{127.0.0.1:35637}
[junit4] 2> 596956 INFO (jetty-launcher-915-thread-2) [ ] o.e.j.s.Server Started @598742ms
[junit4] 2> 596956 INFO (jetty-launcher-915-thread-1) [ ] o.e.j.s.AbstractConnector Started ServerConnector@61bf3a{SSL,[ssl, http/1.1]}{127.0.0.1:37285}
[junit4] 2> 596956 INFO (jetty-launcher-915-thread-1) [ ] o.e.j.s.Server Started @598742ms
[junit4] 2> 596957 INFO (jetty-launcher-915-thread-1) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=37285}
[junit4] 2> 596957 ERROR (jetty-launcher-915-thread-1) [ ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 596957 INFO (jetty-launcher-915-thread-1) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version 7.3.0
[junit4] 2> 596957 INFO (jetty-launcher-915-thread-1) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 596957 INFO (jetty-launcher-915-thread-1) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 596994 INFO (jetty-launcher-915-thread-1) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2018-01-17T04:03:40.363Z
[junit4] 2> 596956 INFO (jetty-launcher-915-thread-2) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=35637}
[junit4] 2> 596995 ERROR (jetty-launcher-915-thread-2) [ ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 596995 INFO (jetty-launcher-915-thread-2) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version 7.3.0
[junit4] 2> 596995 INFO (jetty-launcher-915-thread-2) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 596995 INFO (jetty-launcher-915-thread-2) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 596995 INFO (jetty-launcher-915-thread-2) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2018-01-17T04:03:40.364Z
[junit4] 2> 596992 INFO (jetty-launcher-915-thread-3) [ ] o.a.s.c.SolrXmlConfig Configuration parameter autoReplicaFailoverWorkLoopDelay is ignored
[junit4] 2> 596996 INFO (jetty-launcher-915-thread-3) [ ] o.a.s.c.SolrXmlConfig Configuration parameter autoReplicaFailoverBadNodeExpiration is ignored
[junit4] 2> 596957 INFO (jetty-launcher-915-thread-4) [ ] o.a.s.c.SolrXmlConfig Configuration parameter autoReplicaFailoverWorkLoopDelay is ignored
[junit4] 2> 596997 INFO (jetty-launcher-915-thread-4) [ ] o.a.s.c.SolrXmlConfig Configuration parameter autoReplicaFailoverBadNodeExpiration is ignored
[junit4] 2> 597014 WARN (NIOServerCxn.Factory:0.0.0.0/0.0.0.0:0) [ ] o.a.z.s.NIOServerCnxn caught end of stream exception
[junit4] 2> EndOfStreamException: Unable to read additional data from client sessionid 0x161024965c70002, likely client has closed socket
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:239)
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:203)
[junit4] 2> at java.lang.Thread.run(Thread.java:748)
[junit4] 2> 597014 WARN (NIOServerCxn.Factory:0.0.0.0/0.0.0.0:0) [ ] o.a.z.s.NIOServerCnxn caught end of stream exception
[junit4] 2> EndOfStreamException: Unable to read additional data from client sessionid 0x161024965c70001, likely client has closed socket
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:239)
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:203)
[junit4] 2> at java.lang.Thread.run(Thread.java:748)
[junit4] 2> 597037 INFO (zkConnectionManagerCallback-926-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 597038 INFO (jetty-launcher-915-thread-3) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:34027/solr
[junit4] 2> 597038 INFO (jetty-launcher-915-thread-2) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 597060 INFO (zkConnectionManagerCallback-924-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 597061 INFO (jetty-launcher-915-thread-1) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 597063 INFO (jetty-launcher-915-thread-2) [ ] o.a.s.c.SolrXmlConfig Configuration parameter autoReplicaFailoverWorkLoopDelay is ignored
[junit4] 2> 597063 INFO (jetty-launcher-915-thread-2) [ ] o.a.s.c.SolrXmlConfig Configuration parameter autoReplicaFailoverBadNodeExpiration is ignored
[junit4] 2> 597088 INFO (jetty-launcher-915-thread-4) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:34027/solr
[junit4] 2> 597131 INFO (jetty-launcher-915-thread-1) [ ] o.a.s.c.SolrXmlConfig Configuration parameter autoReplicaFailoverWorkLoopDelay is ignored
[junit4] 2> 597131 INFO (jetty-launcher-915-thread-1) [ ] o.a.s.c.SolrXmlConfig Configuration parameter autoReplicaFailoverBadNodeExpiration is ignored
[junit4] 2> 597151 INFO (zkConnectionManagerCallback-934-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 597153 INFO (zkConnectionManagerCallback-930-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 597162 INFO (jetty-launcher-915-thread-1) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:34027/solr
[junit4] 2> 597168 INFO (zkConnectionManagerCallback-936-thread-1-processing-n:127.0.0.1:43399_solr) [n:127.0.0.1:43399_solr ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 597192 INFO (jetty-launcher-915-thread-2) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:34027/solr
[junit4] 2> 597199 INFO (zkConnectionManagerCallback-946-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 597199 INFO (zkConnectionManagerCallback-940-thread-1-processing-n:127.0.0.1:33819_solr) [n:127.0.0.1:33819_solr ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 597199 INFO (zkConnectionManagerCallback-942-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 597203 WARN (NIOServerCxn.Factory:0.0.0.0/0.0.0.0:0) [ ] o.a.z.s.NIOServerCnxn caught end of stream exception
[junit4] 2> EndOfStreamException: Unable to read additional data from client sessionid 0x161024965c7000a, likely client has closed socket
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:239)
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:203)
[junit4] 2> at java.lang.Thread.run(Thread.java:748)
[junit4] 2> 597205 INFO (zkConnectionManagerCallback-948-thread-1-processing-n:127.0.0.1:35637_solr) [n:127.0.0.1:35637_solr ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 597213 INFO (zkConnectionManagerCallback-951-thread-1-processing-n:127.0.0.1:37285_solr) [n:127.0.0.1:37285_solr ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 597385 INFO (jetty-launcher-915-thread-2) [n:127.0.0.1:35637_solr ] o.a.s.c.Overseer Overseer (id=null) closing
[junit4] 2> 597385 INFO (jetty-launcher-915-thread-1) [n:127.0.0.1:37285_solr ] o.a.s.c.Overseer Overseer (id=null) closing
[junit4] 2> 597385 INFO (jetty-launcher-915-thread-4) [n:127.0.0.1:43399_solr ] o.a.s.c.Overseer Overseer (id=null) closing
[junit4] 2> 597385 INFO (jetty-launcher-915-thread-3) [n:127.0.0.1:33819_solr ] o.a.s.c.Overseer Overseer (id=null) closing
[junit4] 2> 597386 INFO (jetty-launcher-915-thread-2) [n:127.0.0.1:35637_solr ] o.a.s.c.OverseerElectionContext I am going to be the leader 127.0.0.1:35637_solr
[junit4] 2> 597388 INFO (jetty-launcher-915-thread-1) [n:127.0.0.1:37285_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:37285_solr
[junit4] 2> 597388 INFO (jetty-launcher-915-thread-4) [n:127.0.0.1:43399_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:43399_solr
[junit4] 2> 597388 INFO (jetty-launcher-915-thread-2) [n:127.0.0.1:35637_solr ] o.a.s.c.Overseer Overseer (id=99363181042270219-127.0.0.1:35637_solr-n_0000000000) starting
[junit4] 2> 597388 INFO (jetty-launcher-915-thread-3) [n:127.0.0.1:33819_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:33819_solr
[junit4] 2> 597398 INFO (zkCallback-947-thread-1-processing-n:127.0.0.1:35637_solr) [n:127.0.0.1:35637_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (2)
[junit4] 2> 597412 INFO (zkCallback-939-thread-1-processing-n:127.0.0.1:33819_solr) [n:127.0.0.1:33819_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (2)
[junit4] 2> 597412 INFO (zkCallback-935-thread-1-processing-n:127.0.0.1:43399_solr) [n:127.0.0.1:43399_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (2)
[junit4] 2> 597412 INFO (zkCallback-950-thread-1-processing-n:127.0.0.1:37285_solr) [n:127.0.0.1:37285_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (2)
[junit4] 2> 597414 INFO (zkCallback-939-thread-1-processing-n:127.0.0.1:33819_solr) [n:127.0.0.1:33819_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3)
[junit4] 2> 597414 INFO (zkCallback-935-thread-1-processing-n:127.0.0.1:43399_solr) [n:127.0.0.1:43399_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3)
[junit4] 2> 597415 INFO (zkCallback-947-thread-1-processing-n:127.0.0.1:35637_solr) [n:127.0.0.1:35637_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3)
[junit4] 2> 597415 INFO (zkCallback-950-thread-1-processing-n:127.0.0.1:37285_solr) [n:127.0.0.1:37285_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3)
[junit4] 2> 597448 INFO (jetty-launcher-915-thread-2) [n:127.0.0.1:35637_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:35637_solr
[junit4] 2> 597450 INFO (zkCallback-939-thread-1-processing-n:127.0.0.1:33819_solr) [n:127.0.0.1:33819_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4)
[junit4] 2> 597454 INFO (zkCallback-947-thread-1-processing-n:127.0.0.1:35637_solr) [n:127.0.0.1:35637_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4)
[junit4] 2> 597458 INFO (zkCallback-935-thread-1-processing-n:127.0.0.1:43399_solr) [n:127.0.0.1:43399_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4)
[junit4] 2> 597458 INFO (zkCallback-950-thread-1-processing-n:127.0.0.1:37285_solr) [n:127.0.0.1:37285_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4)
[junit4] 2> 597658 INFO (jetty-launcher-915-thread-3) [n:127.0.0.1:33819_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@befef3
[junit4] 2> 597701 INFO (jetty-launcher-915-thread-3) [n:127.0.0.1:33819_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@befef3
[junit4] 2> 597701 INFO (jetty-launcher-915-thread-3) [n:127.0.0.1:33819_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@befef3
[junit4] 2> 597706 INFO (jetty-launcher-915-thread-3) [n:127.0.0.1:33819_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /home/jenkins/workspace/Lucene-Solr-7.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.api.collections.CollectionsAPIDistributedZkTest_1C0E541453B71943-001/tempDir-001/node3
[junit4] 2> 597890 INFO (jetty-launcher-915-thread-2) [n:127.0.0.1:35637_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@befef3
[junit4] 2> 597918 INFO (jetty-launcher-915-thread-2) [n:127.0.0.1:35637_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@befef3
[junit4] 2> 597918 INFO (jetty-launcher-915-thread-2) [n:127.0.0.1:35637_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@befef3
[junit4] 2> 597921 INFO (jetty-launcher-915-thread-2) [n:127.0.0.1:35637_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /home/jenkins/workspace/Lucene-Solr-7.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.api.collections.CollectionsAPIDistributedZkTest_1C0E541453B71943-001/tempDir-001/node2
[junit4] 2> 598001 INFO (jetty-launcher-915-thread-4) [n:127.0.0.1:43399_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@befef3
[junit4] 2> 598031 INFO (jetty-launcher-915-thread-4) [n:127.0.0.1:43399_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@befef3
[junit4] 2> 598031 INFO (jetty-launcher-915-thread-4) [n:127.0.0.1:43399_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@befef3
[junit4] 2> 598034 INFO (jetty-launcher-915-thread-4) [n:127.0.0.1:43399_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /home/jenkins/workspace/Lucene-Solr-7.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.api.collections.CollectionsAPIDistributedZkTest_1C0E541453B71943-001/tempDir-001/node4
[junit4] 2> 598364 INFO (jetty-launcher-915-thread-1) [n:127.0.0.1:37285_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@befef3
[junit4] 2> 598392 INFO (jetty-launcher-915-thread-1) [n:127.0.0.1:37285_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@befef3
[junit4] 2> 598392 INFO (jetty-launcher-915-thread-1) [n:127.0.0.1:37285_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@befef3
[junit4] 2> 598396 INFO (jetty-launcher-915-thread-1) [n:127.0.0.1:37285_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /home/jenkins/workspace/Lucene-Solr-7.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.api.collections.CollectionsAPIDistributedZkTest_1C0E541453B71943-001/tempDir-001/node1
[junit4] 2> 598507 INFO (zkConnectionManagerCallback-960-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 598508 WARN (NIOServerCxn.Factory:0.0.0.0/0.0.0.0:0) [ ] o.a.z.s.NIOServerCnxn caught end of stream exception
[junit4] 2> EndOfStreamException: Unable to read additional data from client sessionid 0x161024965c7000d, likely client has closed socket
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:239)
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:203)
[junit4] 2> at java.lang.Thread.run(Thread.java:748)
[junit4] 2> 598511 INFO (zkConnectionManagerCallback-964-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 598511 INFO (SUITE-CollectionsAPIDistributedZkTest-seed#[1C0E541453B71943]-worker) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (4)
[junit4] 2> 598512 INFO (SUITE-CollectionsAPIDistributedZkTest-seed#[1C0E541453B71943]-worker) [ ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:34027/solr ready
[junit4] 2> 598547 INFO (TEST-CollectionsAPIDistributedZkTest.testSpecificConfigsets-seed#[1C0E541453B71943]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testSpecificConfigsets
[junit4] 2> 598548 INFO (TEST-CollectionsAPIDistributedZkTest.testSpecificConfigsets-seed#[1C0E541453B71943]) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (4)
[junit4] 2> 598606 INFO (qtp23356785-4487) [n:127.0.0.1:35637_solr ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :create with params replicationFactor=1&collection.configName=conf2&name=withconfigset2&nrtReplicas=1&action=CREATE&numShards=1&wt=javabin&version=2 and sendToOCPQueue=true
[junit4] 2> 598608 INFO (OverseerThreadFactory-1913-thread-1-processing-n:127.0.0.1:35637_solr) [n:127.0.0.1:35637_solr ] o.a.s.c.a.c.CreateCollectionCmd Create collection withconfigset2
[junit4] 2> 598718 INFO (OverseerStateUpdate-99363181042270219-127.0.0.1:35637_solr-n_0000000000) [n:127.0.0.1:35637_solr ] o.a.s.c.o.SliceMutator createReplica() {
[junit4] 2> "operation":"ADDREPLICA",
[junit4] 2> "collection":"withconfigset2",
[junit4] 2> "shard":"shard1",
[junit4] 2> "core":"withconfigset2_shard1_replica_n1",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"https://127.0.0.1:37285/solr",
[junit4] 2> "type":"NRT",
[junit4] 2> "waitForFinalState":"false"}
[junit4] 2> 599005 INFO (qtp15452052-4490) [n:127.0.0.1:37285_solr ] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&coreNodeName=core_node2&collection.configName=conf2&newCollection=true&name=withconfigset2_shard1_replica_n1&action=CREATE&numShards=1&collection=withconfigset2&shard=shard1&wt=javabin&version=2&replicaType=NRT
[junit4] 2> 599006 INFO (qtp15452052-4490) [n:127.0.0.1:37285_solr ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores
[junit4] 2> 599115 INFO (zkCallback-950-thread-1-processing-n:127.0.0.1:37285_solr) [n:127.0.0.1:37285_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/withconfigset2/state.json] for collection [withconfigset2] has occurred - updating... (live nodes size: [4])
[junit4] 2> 599118 INFO (zkCallback-950-thread-2-processing-n:127.0.0.1:37285_solr) [n:127.0.0.1:37285_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/withconfigset2/state.json] for collection [withconfigset2] has occurred - updating... (live nodes size: [4])
[junit4] 2> 600043 INFO (qtp15452052-4490) [n:127.0.0.1:37285_solr c:withconfigset2 s:shard1 r:core_node2 x:withconfigset2_shard1_replica_n1] o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.3.0
[junit4] 2> 600093 INFO (qtp15452052-4490) [n:127.0.0.1:37285_solr c:withconfigset2 s:shard1 r:core_node2 x:withconfigset2_shard1_replica_n1] o.a.s.s.IndexSchema [withconfigset2_shard1_replica_n1] Schema name=minimal
[junit4] 2> 600107 INFO (qtp15452052-4490) [n:127.0.0.1:37285_solr c:withconfigset2 s:shard1 r:core_node2 x:withconfigset2_shard1_replica_n1] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
[junit4] 2> 600108 INFO (qtp15452052-4490) [n:127.0.0.1:37285_solr c:withconfigset2 s:shard1 r:core_node2 x:withconfigset2_shard1_replica_n1] o.a.s.c.CoreContainer Creating SolrCore 'withconfigset2_shard1_replica_n1' using configuration from collection withconfigset2, trusted=true
[junit4] 2> 600108 INFO (qtp15452052-4490) [n:127.0.0.1:37285_solr c:withconfigset2 s:shard1 r:core_node2 x:withconfigset2_shard1_replica_n1] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.core.withconfigset2.shard1.replica_n1' (registry 'solr.core.withconfigset2.shard1.replica_n1') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@befef3
[junit4] 2> 600112 INFO (qtp15452052-4490) [n:127.0.0.1:37285_solr c:withconfigset2 s:shard1 r:core_node2 x:withconfigset2_shard1_replica_n1] o.a.s.c.SolrCore solr.RecoveryStrategy.Builder
[junit4] 2> 600112 INFO (qtp15452052-4490) [n:127.0.0.1:37285_solr c:withconfigset2 s:shard1 r:core_node2 x:withconfigset2_shard1_replica_n1] o.a.s.c.SolrCore [[withconfigset2_shard1_replica_n1] ] Opening new SolrCore at [/home/jenkins/workspace/Lucene-Solr-7.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.api.collections.CollectionsAPIDistributedZkTest_1C0E541453B71943-001/tempDir-001/node1/withconfigset2_shard1_replica_n1], dataDir=[/home/jenkins/workspace/Lucene-Solr-7.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.api.collections.CollectionsAPIDistributedZkTest_1C0E541453B71943-001/tempDir-001/node1/withconfigset2_shard1_replica_n1/data/]
[junit4] 2> 600195 INFO (qtp15452052-4490) [n:127.0.0.1:37285_solr c:withconfigset2 s:shard1 r:core_node2 x:withconfigset2_shard1_replica_n1] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
[junit4] 2> 600195 INFO (qtp15452052-4490) [n:127.0.0.1:37285_solr c:withconfigset2 s:shard1 r:core_node2 x:withconfigset2_shard1_replica_n1] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 600207 INFO (qtp15452052-4490) [n:127.0.0.1:37285_solr c:withconfigset2 s:shard1 r:core_node2 x:withconfigset2_shard1_replica_n1] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 600207 INFO (qtp15452052-4490) [n:127.0.0.1:37285_solr c:withconfigset2 s:shard1 r:core_node2 x:withconfigset2_shard1_replica_n1] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 600209 INFO (qtp15452052-4490) [n:127.0.0.1:37285_solr c:withconfigset2 s:shard1 r:core_node2 x:withconfigset2_shard1_replica_n1] o.a.s.s.SolrIndexSearcher Opening [Searcher@eea812[withconfigset2_shard1_replica_n1] main]
[junit4] 2> 600210 INFO (qtp15452052-4490) [n:127.0.0.1:37285_solr c:withconfigset2 s:shard1 r:core_node2 x:withconfigset2_shard1_replica_n1] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf2
[junit4] 2> 600211 INFO (qtp15452052-4490) [n:127.0.0.1:37285_solr c:withconfigset2 s:shard1 r:core_node2 x:withconfigset2_shard1_replica_n1] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf2
[junit4] 2> 600212 INFO (qtp15452052-4490) [n:127.0.0.1:37285_solr c:withconfigset2 s:shard1 r:core_node2 x:withconfigset2_shard1_replica_n1] o.a.s.h.ReplicationHandler Commits will be reserved for 10000ms.
[junit4] 2> 600213 INFO (searcherExecutor-1922-thread-1-processing-n:127.0.0.1:37285_solr x:withconfigset2_shard1_replica_n1 s:shard1 c:withconfigset2 r:core_node2) [n:127.0.0.1:37285_solr c:withconfigset2 s:shard1 r:core_node2 x:withconfigset2_shard1_replica_n1] o.a.s.c.SolrCore [withconfigset2_shard1_replica_n1] Registered new searcher Searcher@eea812[withconfigset2_shard1_replica_n1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 600213 INFO (qtp15452052-4490) [n:127.0.0.1:37285_solr c:withconfigset2 s:shard1 r:core_node2 x:withconfigset2_shard1_replica_n1] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1589810900324319232
[junit4] 2> 600219 INFO (qtp15452052-4490) [n:127.0.0.1:37285_solr c:withconfigset2 s:shard1 r:core_node2 x:withconfigset2_shard1_replica_n1] o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue.
[junit4] 2> 600219 INFO (qtp15452052-4490) [n:127.0.0.1:37285_solr c:withconfigset2 s:shard1 r:core_node2 x:withconfigset2_shard1_replica_n1] o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync
[junit4] 2> 600219 INFO (qtp15452052-4490) [n:127.0.0.1:37285_solr c:withconfigset2 s:shard1 r:core_node2 x:withconfigset2_shard1_replica_n1] o.a.s.c.SyncStrategy Sync replicas to https://127.0.0.1:37285/solr/withconfigset2_shard1_replica_n1/
[junit4] 2> 600219 INFO (qtp15452052-4490) [n:127.0.0.1:37285_solr c:withconfigset2 s:shard1 r:core_node2 x:withconfigset2_shard1_replica_n1] o.a.s.c.SyncStrategy Sync Success - now sync replicas to me
[junit4] 2> 600219 INFO (qtp15452052-4490) [n:127.0.0.1:37285_solr c:withconfigset2 s:shard1 r:core_node2 x:withconfigset2_shard1_replica_n1] o.a.s.c.SyncStrategy https://127.0.0.1:37285/solr/withconfigset2_shard1_replica_n1/ has no replicas
[junit4] 2> 600219 INFO (qtp15452052-4490) [n:127.0.0.1:37285_solr c:withconfigset2 s:shard1 r:core_node2 x:withconfigset2_shard1_replica_n1] o.a.s.c.ShardLeaderElectionContext Found all replicas participating in election, clear LIR
[junit4] 2> 600222 INFO (qtp15452052-4490) [n:127.0.0.1:37285_solr c:withconfigset2 s:shard1 r:core_node2 x:withconfigset2_shard1_replica_n1] o.a.s.c.ShardLeaderElectionContext I am the new leader: https://127.0.0.1:37285/solr/withconfigset2_shard1_replica_n1/ shard1
[junit4] 2> 600324 INFO (zkCallback-950-thread-2-processing-n:127.0.0.1:37285_solr) [n:127.0.0.1:37285_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/withconfigset2/state.json] for collection [withconfigset2] has occurred - updating... (live nodes size: [4])
[junit4] 2> 600324 INFO (zkCallback-950-thread-1-processing-n:127.0.0.1:37285_solr) [n:127.0.0.1:37285_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/withconfigset2/state.json] for collection [withconfigset2] has occurred - updating... (live nodes size: [4])
[junit4] 2> 600373 INFO (qtp15452052-4490) [n:127.0.0.1:37285_solr c:withconfigset2 s:shard1 r:core_node2 x:withconfigset2_shard1_replica_n1] o.a.s.c.ZkController I am the leader, no recovery necessary
[junit4] 2> 600375 INFO (qtp15452052-4490) [n:127.0.0.1:37285_solr c:withconfigset2 s:shard1 r:core_node2 x:withconfigset2_shard1_replica_n1] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={qt=/admin/cores&coreNodeName=core_node2&collection.configName=conf2&newCollection=true&name=withconfigset2_shard1_replica_n1&action=CREATE&numShards=1&collection=withconfigset2&shard=shard1&wt=javabin&version=2&replicaType=NRT} status=0 QTime=1371
[junit4] 2> 600383 INFO (qtp23356785-4487) [n:127.0.0.1:35637_solr ] o.a.s.h.a.CollectionsHandler Wait for new collection to be active for at most 30 seconds. Check all shard replicas
[junit4] 2> 600479 INFO (zkCallback-950-thread-1-processing-n:127.0.0.1:37285_solr) [n:127.0.0.1:37285_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/withconfigset2/state.json] for collection [withconfigset2] has occurred - updating... (live nodes size: [4])
[junit4] 2> 600479 INFO (zkCallback-950-thread-2-processing-n:127.0.0.1:37285_solr) [n:127.0.0.1:37285_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/withconfigset2/state.json] for collection [withconfigset2] has occurred - updating... (live nodes size: [4])
[junit4] 2> 600610 INFO (OverseerCollectionConfigSetProcessor-99363181042270219-127.0.0.1:35637_solr-n_0000000000) [n:127.0.0.1:35637_solr ] o.a.s.c.OverseerTaskQueue Response ZK path: /overseer/collection-queue-work/qnr-0000000000 doesn't exist. Requestor may have disconnected from ZooKeeper
[junit4] 2> 601384 INFO (qtp23356785-4487) [n:127.0.0.1:35637_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={replicationFactor=1&collection.configName=conf2&name=withconfigset2&nrtReplicas=1&action=CREATE&numShards=1&wt=javabin&version=2} status=0 QTime=2777
[junit4] 2> 601385 INFO (TEST-CollectionsAPIDistributedZkTest.testSpecificConfigsets-seed#[1C0E541453B71943]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testSpecificConfigsets
[junit4] 2> 601422 INFO (TEST-CollectionsAPIDistributedZkTest.deletePartiallyCreatedCollection-seed#[1C0E541453B71943]) [ ] o.a.s.SolrTestCaseJ4 ###Starting deletePartiallyCreatedCollection
[junit4] 2> 601423 INFO (TEST-CollectionsAPIDistributedZkTest.deletePartiallyCreatedCollection-seed#[1C0E541453B71943]) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (4)
[junit4] 2> 601426 INFO (qtp23356785-4483) [n:127.0.0.1:35637_solr ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :delete with params name=withconfigset2&action=DELETE&wt=javabin&version=2 and sendToOCPQueue=true
[junit4] 2> 601428 INFO (OverseerThreadFactory-1913-thread-2-processing-n:127.0.0.1:35637_solr) [n:127.0.0.1:35637_solr ] o.a.s.c.a.c.OverseerCollectionMessageHandler Executing Collection Cmd : action=UNLOAD&deleteInstanceDir=true&deleteDataDir=true
[junit4] 2> 601431 INFO (qtp15452052-4485) [n:127.0.0.1:37285_solr ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.core.withconfigset2.shard1.replica_n1, tag=null
[junit4] 2> 601431 INFO (qtp15452052-4485) [n:127.0.0.1:37285_solr ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@1c3688d: rootName = null, domain = solr.core.withconfigset2.shard1.replica_n1, service url = null, agent id = null] for registry solr.core.withconfigset2.shard1.replica_n1 / com.codahale.metrics.MetricRegistry@3b7227
[junit4] 2> 601458 INFO (qtp15452052-4485) [n:127.0.0.1:37285_solr ] o.a.s.c.SolrCore [withconfigset2_shard1_replica_n1] CLOSING SolrCore org.apache.solr.core.SolrCore@1e02fc7
[junit4] 2> 601458 INFO (qtp15452052-4485) [n:127.0.0.1:37285_solr ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.core.withconfigset2.shard1.replica_n1, tag=31469511
[junit4] 2> 601458 INFO (qtp15452052-4485) [n:127.0.0.1:37285_solr ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.collection.withconfigset2.shard1.leader, tag=31469511
[junit4] 2> 601465 INFO (qtp15452052-4485) [n:127.0.0.1:37285_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={deleteInstanceDir=true&core=withconfigset2_shard1_replica_n1&qt=/admin/cores&deleteDataDir=true&action=UNLOAD&wt=javabin&version=2} status=0 QTime=34
[junit4] 2> 602171 INFO (qtp23356785-4483) [n:127.0.0.1:35637_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={name=withconfigset2&action=DELETE&wt=javabin&version=2} status=0 QTime=745
[junit4] 2> 602173 INFO (qtp23356785-4487) [n:127.0.0.1:35637_solr ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :create with params replicationFactor=1&collection.configName=conf&name=halfdeletedcollection&nrtReplicas=1&action=CREATE&numShards=2&createNodeSet=&wt=javabin&version=2 and sendToOCPQueue=true
[junit4] 2> 602175 INFO (OverseerThreadFactory-1913-thread-3-processing-n:127.0.0.1:35637_solr) [n:127.0.0.1:35637_solr ] o.a.s.c.a.c.CreateCollectionCmd Create collection halfdeletedcollection
[junit4] 2> 602175 INFO (OverseerCollectionConfigSetProcessor-99363181042270219-127.0.0.1:35637_solr-n_0000000000) [n:127.0.0.1:35637_solr ] o.a.s.c.OverseerTaskQueue Response ZK path: /overseer/collection-queue-work/qnr-0000000002 doesn't exist. Requestor may have disconnected from ZooKeeper
[junit4] 2> 602176 WARN (OverseerThreadFactory-1913-thread-3-processing-n:127.0.0.1:35637_solr) [n:127.0.0.1:35637_solr ] o.a.s.c.a.c.CreateCollectionCmd It is unusual to create a collection (halfdeletedcollection) without cores.
[junit4] 2> 602381 INFO (qtp23356785-4487) [n:127.0.0.1:35637_solr ] o.a.s.h.a.CollectionsHandler Wait for new collection to be active for at most 30 seconds. Check all shard replicas
[junit4] 2> 602381 INFO (qtp23356785-4487) [n:127.0.0.1:35637_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={replicationFactor=1&collection.configName=conf&name=halfdeletedcollection&nrtReplicas=1&action=CREATE&numShards=2&createNodeSet=&wt=javabin&version=2} status=0 QTime=208
[junit4] 2> 602384 INFO (qtp23356785-4483) [n:127.0.0.1:35637_solr ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :addreplica with params dataDir=/home/jenkins/workspace/Lucene-Solr-7.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.api.collections.CollectionsAPIDistributedZkTest_1C0E541453B71943-001/tempDir-002&action=ADDREPLICA&collection=halfdeletedcollection&shard=shard1&type=NRT&wt=javabin&version=2 and sendToOCPQueue=true
[junit4] 2> 602386 INFO (OverseerCollectionConfigSetProcessor-99363181042270219-127.0.0.1:35637_solr-n_0000000000) [n:127.0.0.1:35637_solr ] o.a.s.c.OverseerTaskQueue Response ZK path: /overseer/collection-queue-work/qnr-0000000004 doesn't exist. Requestor may have disconnected from ZooKeeper
[junit4] 2> 602387 INFO (OverseerThreadFactory-1913-thread-4-processing-n:127.0.0.1:35637_solr) [n:127.0.0.1:35637_solr ] o.a.s.c.a.c.AddReplicaCmd Node Identified 127.0.0.1:43399_solr for creating new replica
[junit4] 2> 602390 INFO (OverseerStateUpdate-99363181042270219-127.0.0.1:35637_solr-n_0000000000) [n:127.0.0.1:35637_solr ] o.a.s.c.o.SliceMutator createReplica() {
[junit4] 2> "operation":"addreplica",
[junit4] 2> "collection":"halfdeletedcollection",
[junit4] 2> "shard":"shard1",
[junit4] 2> "core":"halfdeletedcollection_shard1_replica_n41",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"https://127.0.0.1:43399/solr",
[junit4] 2> "node_name":"127.0.0.1:43399_solr",
[junit4] 2> "type":"NRT"}
[junit4] 2> 602652 INFO (qtp15097313-4476) [n:127.0.0.1:43399_solr ] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&coreNodeName=core_node42&dataDir=/home/jenkins/workspace/Lucene-Solr-7.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.api.collections.CollectionsAPIDistributedZkTest_1C0E541453B71943-001/tempDir-002&collection.configName=conf&name=halfdeletedcollection_shard1_replica_n41&action=CREATE&collection=halfdeletedcollection&shard=shard1&wt=javabin&version=2&replicaType=NRT
[junit4] 2> 602653 INFO (qtp15097313-4476) [n:127.0.0.1:43399_solr ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores
[junit4] 2> 602680 INFO (qtp15097313-4476) [n:127.0.0.1:43399_solr c:halfdeletedcollection s:shard1 r:core_node42 x:halfdeletedcollection_shard1_replica_n41] o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.3.0
[junit4] 2> 602704 INFO (qtp15097313-4476) [n:127.0.0.1:43399_solr c:halfdeletedcollection s:shard1 r:core_node42 x:halfdeletedcollection_shard1_replica_n41] o.a.s.s.IndexSchema [halfdeletedcollection_shard1_replica_n41] Schema name=minimal
[junit4] 2> 602710 INFO (qtp15097313-4476) [n:127.0.0.1:43399_solr c:halfdeletedcollection s:shard1 r:core_node42 x:halfdeletedcollection_shard1_replica_n41] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
[junit4] 2> 602710 INFO (qtp15097313-4476) [n:127.0.0.1:43399_solr c:halfdeletedcollection s:shard1 r:core_node42 x:halfdeletedcollection_shard1_replica_n41] o.a.s.c.CoreContainer Creating SolrCore 'halfdeletedcollection_shard1_replica_n41' using configuration from collection halfdeletedcollection, trusted=true
[junit4] 2> 602711 INFO (qtp15097313-4476) [n:127.0.0.1:43399_solr c:halfdeletedcollection s:shard1 r:core_node42 x:halfdeletedcollection_shard1_replica_n41] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.core.halfdeletedcollection.shard1.replica_n41' (registry 'solr.core.halfdeletedcollection.shard1.replica_n41') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@befef3
[junit4] 2> 602711 INFO (qtp15097313-4476) [n:127.0.0.1:43399_solr c:halfdeletedcollection s:shard1 r:core_node42 x:halfdeletedcollection_shard1_replica_n41] o.a.s.c.SolrCore solr.RecoveryStrategy.Builder
[junit4] 2> 602711 INFO (qtp15097313-4476) [n:127.0.0.1:43399_solr c:halfdeletedcollection s:shard1 r:core_node42 x:halfdeletedcollection_shard1_replica_n41] o.a.s.c.SolrCore [[halfdeletedcollection_shard1_replica_n41] ] Opening new SolrCore at [/home/jenkins/workspace/Lucene-Solr-7.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.api.collections.CollectionsAPIDistributedZkTest_1C0E541453B71943-001/tempDir-001/node4/halfdeletedcollection_shard1_replica_n41], dataDir=[/home/jenkins/workspace/Lucene-Solr-7.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.api.collections.CollectionsAPIDistributedZkTest_1C0E541453B71943-001/tempDir-002/]
[junit4] 2> 602757 INFO (zkCallback-935-thread-1-processing-n:127.0.0.1:43399_solr) [n:127.0.0.1:43399_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/halfdeletedcollection/state.json] for collection [halfdeletedcollection] has occurred - updating... (live nodes size: [4])
[junit4] 2> 602757 INFO (zkCallback-935-thread-2-processing-n:127.0.0.1:43399_solr) [n:127.0.0.1:43399_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/halfdeletedcollection/state.json] for collection [halfdeletedcollection] has occurred - updating... (live nodes size: [4])
[junit4] 2> 602829 INFO (qtp15097313-4476) [n:127.0.0.1:43399_solr c:halfdeletedcollection s:shard1 r:core_node42 x:halfdeletedcollection_shard1_replica_n41] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
[junit4] 2> 602829 INFO (qtp15097313-4476) [n:127.0.0.1:43399_solr c:halfdeletedcollection s:shard1 r:core_node42 x:halfdeletedcollection_shard1_replica_n41] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 602831 INFO (qtp15097313-4476) [n:127.0.0.1:43399_solr c:halfdeletedcollection s:shard1 r:core_node42 x:halfdeletedcollection_shard1_replica_n41] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 602831 INFO (qtp15097313-4476) [n:127.0.0.1:43399_solr c:halfdeletedcollection s:shard1 r:core_node42 x:halfdeletedcollection_shard1_replica_n41] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 602843 INFO (qtp15097313-4476) [n:127.0.0.1:43399_solr c:halfdeletedcollection s:shard1 r:core_node42 x:halfdeletedcollection_shard1_replica_n41] o.a.s.s.SolrIndexSearcher Opening [Searcher@b1b571[halfdeletedcollection_shard1_replica_n41] main]
[junit4] 2> 602844 INFO (qtp15097313-4476) [n:127.0.0.1:43399_solr c:halfdeletedcollection s:shard1 r:core_node42 x:halfdeletedcollection_shard1_replica_n41] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf
[junit4] 2> 602845 INFO (qtp15097313-4476) [n:127.0.0.1:43399_solr c:halfdeletedcollection s:shard1 r:core_node42 x:halfdeletedcollection_shard1_replica_n41] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf
[junit4] 2> 602846 INFO (qtp15097313-4476) [n:127.0.0.1:43399_solr c:halfdeletedcollection s:shard1 r:core_node42 x:halfdeletedcollection_shard1_replica_n41] o.a.s.h.ReplicationHandler Commits will be reserved for 10000ms.
[junit4] 2> 602847 INFO (searcherExecutor-1927-thread-1-processing-n:127.0.0.1:43399_solr x:halfdeletedcollection_shard1_replica_n41 s:shard1 c:halfdeletedcollection r:core_node42) [n:127.0.0.1:43399_solr c:halfdeletedcollection s:shard1 r:core_node42 x:halfdeletedcollection_shard1_replica_n41] o.a.s.c.SolrCore [halfdeletedcollection_shard1_replica_n41] Registered new searcher Searcher@b1b571[halfdeletedcollection_shard1_replica_n41] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 602847 INFO (qtp15097313-4476) [n:127.0.0.1:43399_solr c:halfdeletedcollection s:shard1 r:core_node42 x:halfdeletedcollection_shard1_replica_n41] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1589810903086268416
[junit4] 2> 602853 INFO (qtp15097313-4476) [n:127.0.0.1:43399_solr c:halfdeletedcollection s:shard1 r:core_node42 x:halfdeletedcollection_shard1_replica_n41] o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue.
[junit4] 2> 602853 INFO (qtp15097313-4476) [n:127.0.0.1:43399_solr c:halfdeletedcollection s:shard1 r:core_node42 x:halfdeletedcollection_shard1_replica_n41] o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync
[junit4] 2> 602853 INFO (qtp15097313-4476) [n:127.0.0.1:43399_solr c:halfdeletedcollection s:shard1 r:core_node42 x:halfdeletedcollection_shard1_replica_n41] o.a.s.c.SyncStrategy Sync replicas to https://127.0.0.1:43399/solr/halfdeletedcollection_shard1_replica_n41/
[junit4] 2> 602853 INFO (qtp15097313-4476) [n:127.0.0.1:43399_solr c:halfdeletedcollection s:shard1 r:core_node42 x:halfdeletedcollection_shard1_replica_n41] o.a.s.c.SyncStrategy Sync Success - now sync replicas to me
[junit4] 2> 602853 INFO (qtp15097313-4476) [n:127.0.0.1:43399_solr c:halfdeletedcollection s:shard1 r:core_node42 x:halfdeletedcollection_shard1_replica_n41] o.a.s.c.SyncStrategy https://127.0.0.1:43399/solr/halfdeletedcollection_shard1_replica_n41/ has no replicas
[junit4] 2> 602853 INFO (qtp15097313-4476) [n:127.0.0.1:43399_solr c:halfdeletedcollection s:shard1 r:core_node42 x:halfdeletedcollection_shard1_replica_n41] o.a.s.c.ShardLeaderElectionContext Found all replicas participating in election, clear LIR
[junit4] 2> 602856 INFO (qtp15097313-4476) [n:127.0.0.1:43399_solr c:halfdeletedcollection s:shard1 r:core_node42 x:halfdeletedcollection_shard1_replica_n41] o.a.s.c.ShardLeaderElectionContext I am the new leader: https://127.0.0.1:43399/solr/halfdeletedcollection_shard1_replica_n41/ shard1
[junit4] 2> 602958 INFO (zkCallback-935-thread-2-processing-n:127.0.0.1:43399_solr) [n:127.0.0.1:43399_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/halfdeletedcollection/state.json] for collection [halfdeletedcollection] has occurred - updating... (live nodes size: [4])
[junit4] 2> 602958 INFO (zkCallback-935-thread-1-processing-n:127.0.0.1:43399_solr) [n:127.0.0.1:43399_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/halfdeletedcollection/state.json] for collection [halfdeletedcollection] has occurred - updating... (live nodes size: [4])
[junit4] 2> 603007 INFO (qtp15097313-4476) [n:127.0.0.1:43399_solr c:halfdeletedcollection s:shard1 r:core_node42 x:halfdeletedcollection_shard1_replica_n41] o.a.s.c.ZkController I am the leader, no recovery necessary
[junit4] 2> 603009 INFO (qtp15097313-4476) [n:127.0.0.1:43399_solr c:halfdeletedcollection s:shard1 r:core_node42 x:halfdeletedcollection_shard1_replica_n41] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={qt=/admin/cores&coreNodeName=core_node42&dataDir=/home/jenkins/workspace/Lucene-Solr-7.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.api.collections.CollectionsAPIDistributedZkTest_1C0E541453B71943-001/tempDir-002&collection.configName=conf&name=halfdeletedcollection_shard1_replica_n41&action=CREATE&collection=halfdeletedcollection&shard=shard1&wt=javabin&version=2&replicaType=NRT} status=0 QTime=358
[junit4] 2> 603013 INFO (qtp23356785-4483) [n:127.0.0.1:35637_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={dataDir=/home/jenkins/workspace/Lucene-Solr-7.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.api.collections.CollectionsAPIDistributedZkTest_1C0E541453B71943-001/tempDir-002&action=ADDREPLICA&collection=halfdeletedcollection&shard=shard1&type=NRT&wt=javabin&version=2} status=0 QTime=629
[junit4] 2> 603015 INFO (qtp23356785-4487) [n:127.0.0.1:35637_solr ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :delete with params name=halfdeletedcollection&action=DELETE&wt=javabin&version=2 and sendToOCPQueue=true
[junit4] 2> 603017 INFO (OverseerCollectionConfigSetProcessor-99363181042270219-127.0.0.1:35637_solr-n_0000000000) [n:127.0.0.1:35637_solr ] o.a.s.c.OverseerTaskQueue Response ZK path: /overseer/collection-queue-work/qnr-0000000006 doesn't exist. Requestor may have disconnected from ZooKeeper
[junit4] 2> 603018 INFO (OverseerThreadFactory-1913-thread-5-processing-n:127.0.0.1:35637_solr) [n:127.0.0.1:35637_solr ] o.a.s.c.a.c.OverseerCollectionMessageHandler Executing Collection Cmd : action=UNLOAD&deleteInstanceDir=true&deleteDataDir=true
[junit4] 2> 603020 INFO (qtp15097313-4470) [n:127.0.0.1:43399_solr ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.core.halfdeletedcollection.shard1.replica_n41, tag=null
[junit4] 2> 603020 INFO (qtp15097313-4470) [n:127.0.0.1:43399_solr ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@e9f222: rootName = null, domain = solr.core.halfdeletedcollection.shard1.replica_n41, service url = null, agent id = null] for registry solr.core.halfdeletedcollection.shard1.replica_n41 / com.codahale.metrics.MetricRegistry@12b8ace
[junit4] 2> 603048 INFO (qtp15097313-4470) [n:127.0.0.1:43399_solr ] o.a.s.c.SolrCore [halfdeletedcollection_shard1_replica_n41] CLOSING SolrCore org.apache.solr.core.SolrCore@dbf657
[junit4] 2> 603048 INFO (qtp15097313-4470) [n:127.0.0.1:43399_solr ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.core.halfdeletedcollection.shard1.replica_n41, tag=14415447
[junit4] 2> 603048 INFO (qtp15097313-4470) [n:127.0.0.1:43399_solr ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.collection.halfdeletedcollection.shard1.leader, tag=14415447
[junit4] 2> 603052 INFO (qtp15097313-4470) [n:127.0.0.1:43399_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={deleteInstanceDir=true&core=halfdeletedcollection_shard1_replica_n41&qt=/admin/cores&deleteDataDir=true&action=UNLOAD&wt=javabin&version=2} status=0 QTime=31
[junit4] 2> 603759 INFO (qtp23356785-4487) [n:127.0.0.1:35637_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={name=halfdeletedcollection&action=DELETE&wt=javabin&version=2} status=0 QTime=743
[junit4] 2> 603762 INFO (qtp23356785-4483) [n:127.0.0.1:35637_solr ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :list with params action=LIST&wt=javabin&version=2 and sendToOCPQueue=true
[junit4] 2> 603762 INFO (qtp23356785-4483) [n:127.0.0.1:35637_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> 603764 INFO (qtp23356785-4487) [n:127.0.0.1:35637_solr ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :create with params replicationFactor=1&collection.configName=conf&name=halfdeletedcollection&nrtReplicas=1&action=CREATE&numShards=2&wt=javabin&version=2 and sendToOCPQueue=true
[junit4] 2> 603766 INFO (OverseerThreadFactory-1913-thread-5-processing-n:127.0.0.1:35637_solr) [n:127.0.0.1:35637_solr ] o.a.s.c.a.c.CreateCollectionCmd Create collection halfdeletedcollection
[junit4] 2> 603766 INFO (OverseerCollectionConfigSetProcessor-99363181042270219-127.0.0.1:35637_solr-n_0000000000) [n:127.0.0.1:35637_solr ] 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> 603977 INFO (OverseerStateUpdate-99363181042270219-127.0.0.1:35637_solr-n_0000000000) [n:127.0.0.1:35637_solr ] o.a.s.c.o.SliceMutator createReplica() {
[junit4] 2> "operation":"ADDREPLICA",
[junit4] 2> "collection":"halfdeletedcollection",
[junit4] 2> "shard":"shard1",
[junit4] 2> "core":"halfdeletedcollection_shard1_replica_n1",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"https://127.0.0.1:43399/solr",
[junit4] 2> "type":"NRT",
[junit4] 2> "waitForFinalState":"false"}
[junit4] 2> 603979 INFO (OverseerStateUpdate-99363181042270219-127.0.0.1:35637_solr-n_0000000000) [n:127.0.0.1:35637_solr ] o.a.s.c.o.SliceMutator createReplica() {
[junit4] 2> "operation":"ADDREPLICA",
[junit4] 2> "collection":"halfdeletedcollection",
[junit4] 2> "shard":"shard2",
[junit4] 2> "core":"halfdeletedcollection_shard2_replica_n2",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"https://127.0.0.1:37285/solr",
[junit4] 2> "type":"NRT",
[junit4] 2> "waitForFinalState":"false"}
[junit4] 2> 604187 INFO (qtp15097313-4476) [n:127.0.0.1:43399_solr ] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&coreNodeName=core_node3&collection.configName=conf&newCollection=true&name=halfdeletedcollection_shard1_replica_n1&action=CREATE&numShards=2&collection=halfdeletedcollection&shard=shard1&wt=javabin&version=2&replicaType=NRT
[junit4] 2> 604195 INFO (qtp15452052-4490) [n:127.0.0.1:37285_solr ] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&coreNodeName=core_node4&collection.configName=conf&newCollection=true&name=halfdeletedcollection_shard2_replica_n2&action=CREATE&numShards=2&collection=halfdeletedcollection&shard=shard2&wt=javabin&version=2&replicaType=NRT
[junit4] 2> 604310 INFO (zkCallback-935-thread-2-processing-n:127.0.0.1:43399_solr) [n:127.0.0.1:43399_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/halfdeletedcollection/state.json] for collection [halfdeletedcollection] has occurred - updating... (live nodes size: [4])
[junit4] 2> 604310 INFO (zkCallback-935-thread-1-processing-n:127.0.0.1:43399_solr) [n:127.0.0.1:43399_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/halfdeletedcollection/state.json] for collection [halfdeletedcollection] has occurred - updating... (live nodes size: [4])
[junit4] 2> 604314 INFO (zkCallback-950-thread-1-processing-n:127.0.0.1:37285_solr) [n:127.0.0.1:37285_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/halfdeletedcollection/state.json] for collection [halfdeletedcollection] has occurred - updating... (live nodes size: [4])
[junit4] 2> 604314 INFO (zkCallback-950-thread-2-processing-n:127.0.0.1:37285_solr) [n:127.0.0.1:37285_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/halfdeletedcollection/state.json] for collection [halfdeletedcollection] has occurred - updating... (live nodes size: [4])
[junit4] 2> 605239 INFO (qtp15097313-4476) [n:127.0.0.1:43399_solr c:halfdeletedcollection s:shard1 r:core_node3 x:halfdeletedcollection_shard1_replica_n1] o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.3.0
[junit4] 2> 605314 INFO (qtp15452052-4490) [n:127.0.0.1:37285_solr c:halfdeletedcollection s:shard2 r:core_node4 x:halfdeletedcollection_shard2_replica_n2] o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.3.0
[junit4] 2> 605412 INFO (qtp15097313-4476) [n:127.0.0.1:43399_solr c:halfdeletedcollection s:shard1 r:core_node3 x:halfdeletedcollection_shard1_replica_n1] o.a.s.s.IndexSchema [halfdeletedcollection_shard1_replica_n1] Schema name=minimal
[junit4] 2> 605413 INFO (qtp15452052-4490) [n:127.0.0.1:37285_solr c:halfdeletedcollection s:shard2 r:core_node4 x:halfdeletedcollection_shard2_replica_n2] o.a.s.s.IndexSchema [halfdeletedcollection_shard2_replica_n2] Schema name=minimal
[junit4] 2> 605439 INFO (qtp15452052-4490) [n:127.0.0.1:37285_solr c:halfdeletedcollection s:shard2 r:core_node4 x:halfdeletedcollection_shard2_replica_n2] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
[junit4] 2> 605439 INFO (qtp15452052-4490) [n:127.0.0.1:37285_solr c:halfdeletedcollection s:shard2 r:core_node4 x:halfdeletedcollection_shard2_replica_n2] o.a.s.c.CoreContainer Creating SolrCore 'halfdeletedcollection_shard2_replica_n2' using configuration from collection halfdeletedcollection, trusted=true
[junit4] 2> 605447 INFO (qtp15097313-4476) [n:127.0.0.1:43399_solr c:halfdeletedcollection s:shard1 r:core_node3 x:halfdeletedcollection_shard1_replica_n1] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
[junit4] 2> 605448 INFO (qtp15097313-4476) [n:127.0.0.1:43399_solr c:halfdeletedcollection s:shard1 r:core_node3 x:halfdeletedcollection_shard1_replica_n1] o.a.s.c.CoreContainer Creating SolrCore 'halfdeletedcollection_shard1_replica_n1' using configuration from collection halfdeletedcollection, trusted=true
[junit4] 2> 605449 INFO (qtp15097313-4476) [n:127.0.0.1:43399_solr c:halfdeletedcollection s:shard1 r:core_node3 x:halfdeletedcollection_shard1_replica_n1] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.core.halfdeletedcollection.shard1.replica_n1' (registry 'solr.core.halfdeletedcollection.shard1.replica_n1') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@befef3
[junit4] 2> 605449 INFO (qtp15097313-4476) [n:127.0.0.1:43399_solr c:halfdeletedcollection s:shard1 r:core_node3 x:halfdeletedcollection_shard1_replica_n1] o.a.s.c.SolrCore solr.RecoveryStrategy.Builder
[junit4] 2> 605449 INFO (qtp15097313-4476) [n:127.0.0.1:43399_solr c:halfdeletedcollection s:shard1 r:core_node3 x:halfdeletedcollection_shard1_replica_n1] o.a.s.c.SolrCore [[halfdeletedcollection_shard1_replica_n1] ] Opening new SolrCore at [/home/jenkins/workspace/Lucene-Solr-7.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.api.collections.CollectionsAPIDistributedZkTest_1C0E541453B71943-001/tempDir-001/node4/halfdeletedcollection_shard1_replica_n1], dataDir=[/home/jenkins/workspace/Lucene-Solr-7.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.api.collections.CollectionsAPIDistributedZkTest_1C0E541453B71943-001/tempDir-001/node4/halfdeletedcollection_shard1_replica_n1/data/]
[junit4] 2> 605450 INFO (qtp15452052-4490) [n:127.0.0.1:37285_solr c:halfdeletedcollection s:shard2 r:core_node4 x:halfdeletedcollection_shard2_replica_n2] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.core.halfdeletedcollection.shard2.replica_n2' (registry 'solr.core.halfdeletedcollection.shard2.replica_n2') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@befef3
[junit4] 2> 605450 INFO (qtp15452052-4490) [n:127.0.0.1:37285_solr c:halfdeletedcollection s:shard2 r:core_node4 x:halfdeletedcollection_shard2_replica_n2] o.a.s.c.SolrCore solr.RecoveryStrategy.Builder
[junit4] 2> 605450 INFO (qtp15452052-4490) [n:127.0.0.1:37285_solr c:halfdeletedcollection s:shard2 r:core_node4 x:halfdeletedcollection_shard2_replica_n2] o.a.s.c.SolrCore [[halfdeletedcollection_shard2_replica_n2] ] Opening new SolrCore at [/home/jenkins/workspace/Lucene-Solr-7.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.api.collections.CollectionsAPIDistributedZkTest_1C0E541453B71943-001/tempDir-001/node1/halfdeletedcollection_shard2_replica_n2], dataDir=[/home/jenkins/workspace/Lucene-Solr-7.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.api.collections.CollectionsAPIDistributedZkTest_1C0E541453B71943-001/tempDir-001/node1/halfdeletedcollection_shard2_replica_n2/data/]
[junit4] 2> 605828 INFO (qtp15097313-4476) [n:127.0.0.1:43399_solr c:halfdeletedcollection s:shard1 r:core_node3 x:halfdeletedcollection_shard1_replica_n1] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
[junit4] 2> 605828 INFO (qtp15097313-4476) [n:127.0.0.1:43399_solr c:halfdeletedcollection s:shard1 r:core_node3 x:halfdeletedcollection_shard1_replica_n1] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 605830 INFO (qtp15097313-4476) [n:127.0.0.1:43399_solr c:halfdeletedcollection s:shard1 r:core_node3 x:halfdeletedcollection_shard1_replica_n1] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 605830 INFO (qtp15097313-4476) [n:127.0.0.1:43399_solr c:halfdeletedcollection s:shard1 r:core_node3 x:halfdeletedcollection_shard1_replica_n1] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 605833 INFO (qtp15097313-4476) [n:127.0.0.1:43399_solr c:halfdeletedcollection s:shard1 r:core_node3 x:halfdeletedcollection_shard1_replica_n1] o.a.s.s.SolrIndexSearcher Opening [Searcher@1b1a9fd[halfdeletedcollection_shard1_replica_n1] main]
[junit4] 2> 605835 INFO (qtp15097313-4476) [n:127.0.0.1:43399_solr c:halfdeletedcollection s:shard1 r:core_node3 x:halfdeletedcollection_shard1_replica_n1] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf
[junit4] 2> 605836 INFO (qtp15097313-4476) [n:127.0.0.1:43399_solr c:halfdeletedcollection s:shard1 r:core_node3 x:halfdeletedcollection_shard1_replica_n1] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf
[junit4] 2> 605837 INFO (qtp15097313-4476) [n:127.0.0.1:43399_solr c:halfdeletedcollection s:shard1 r:core_node3 x:halfdeletedcollection_shard1_replica_n1] o.a.s.h.ReplicationHandler Commits will be reserved for 10000ms.
[junit4] 2> 605881 INFO (searcherExecutor-1933-thread-1-processing-n:127.0.0.1:43399_solr x:halfdeletedcollection_shard1_replica_n1 s:shard1 c:halfdeletedcollection r:core_node3) [n:127.0.0.1:43399_solr c:halfdeletedcollection s:shard1 r:core_node3 x:halfdeletedcollection_shard1_replica_n1] o.a.s.c.SolrCore [halfdeletedcollection_shard1_replica_n1] Registered new searcher Searcher@1b1a9fd[halfdeletedcollection_shard1_replica_n1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 605881 INFO (qtp15097313-4476) [n:127.0.0.1:43399_solr c:halfdeletedcollection s:shard1 r:core_node3 x:halfdeletedcollection_shard1_replica_n1] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1589810906267648000
[junit4] 2> 605890 INFO (qtp15097313-4476) [n:127.0.0.1:43399_solr c:halfdeletedcollection s:shard1 r:core_node3 x:halfdeletedcollection_shard1_replica_n1] o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue.
[junit4] 2> 605890 INFO (qtp15097313-4476) [n:127.0.0.1:43399_solr c:halfdeletedcollection s:shard1 r:core_node3 x:halfdeletedcollection_shard1_replica_n1] o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync
[junit4] 2> 605890 INFO (qtp15097313-4476) [n:127.0.0.1:43399_solr c:halfdeletedcollection s:shard1 r:core_node3 x:halfdeletedcollection_shard1_replica_n1] o.a.s.c.SyncStrategy Sync replicas to https://127.0.0.1:43399/solr/halfdeletedcollection_shard1_replica_n1/
[junit4] 2> 605890 INFO (qtp15097313-4476) [n:127.0.0.1:43399_solr c:halfdeletedcollection s:shard1 r:core_node3 x:halfdeletedcollection_shard1_replica_n1] o.a.s.c.SyncStrategy Sync Success - now sync replicas to me
[junit4] 2> 605890 INFO (qtp15097313-4476) [n:127.0.0.1:43399_solr c:halfdeletedcollection s:shard1 r:core_node3 x:halfdeletedcollection_shard1_replica_n1] o.a.s.c.SyncStrategy https://127.0.0.1:43399/solr/halfdeletedcollection_shard1_replica_n1/ has no replicas
[junit4] 2> 605890 INFO (qtp15097313-4476) [n:127.0.0.1:43399_solr c:halfdeletedcollection s:shard1 r:core_node3 x:halfdeletedcollection_shard1_replica_n1] o.a.s.c.ShardLeaderElectionContext Found all replicas participating in election, clear LIR
[junit4] 2> 605896 INFO (qtp15097313-4476) [n:127.0.0.1:43399_solr c:halfdeletedcollection s:shard1 r:core_node3 x:halfdeletedcollection_shard1_replica_n1] o.a.s.c.ShardLeaderElectionContext I am the new leader: https://127.0.0.1:43399/solr/halfdeletedcollection_shard1_replica_n1/ shard1
[junit4] 2> 605911 INFO (qtp15452052-4490) [n:127.0.0.1:37285_solr c:halfdeletedcollection s:shard2 r:core_node4 x:halfdeletedcollection_shard2_replica_n2] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
[junit4] 2> 605911 INFO (qtp15452052-4490) [n:127.0.0.1:37285_solr c:halfdeletedcollection s:shard2 r:core_node4 x:halfdeletedcollection_shard2_replica_n2] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 605913 INFO (qtp15452052-4490) [n:127.0.0.1:37285_solr c:halfdeletedcollection s:shard2 r:core_node4 x:halfdeletedcollection_shard2_replica_n2] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 605913 INFO (qtp15452052-4490) [n:127.0.0.1:37285_solr c:halfdeletedcollection s:shard2 r:core_node4 x:halfdeletedcollection_shard2_replica_n2] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 605916 INFO (qtp15452052-4490) [n:127.0.0.1:37285_solr c:halfdeletedcollection s:shard2 r:core_node4 x:halfdeletedcollection_shard2_replica_n2] o.a.s.s.SolrIndexSearcher Opening [Searcher@1e62a6b[halfdeletedcollection_shard2_replica_n2] main]
[junit4] 2> 605918 INFO (qtp15452052-4490) [n:127.0.0.1:37285_solr c:halfdeletedcollection s:shard2 r:core_node4 x:halfdeletedcollection_shard2_replica_n2] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf
[junit4] 2> 605919 INFO (qtp15452052-4490) [n:127.0.0.1:37285_solr c:halfdeletedcollection s:shard2 r:core_node4 x:halfdeletedcollection_shard2_replica_n2] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf
[junit4] 2> 605920 INFO (qtp15452052-4490) [n:127.0.0.1:37285_solr c:halfdeletedcollection s:shard2 r:core_node4 x:halfdeletedcollection_shard2_replica_n2] o.a.s.h.ReplicationHandler Commits will be reserved for 10000ms.
[junit4] 2> 605920 INFO (qtp15452052-4490) [n:127.0.0.1:37285_solr c:halfdeletedcollection s:shard2 r:core_node4 x:halfdeletedcollection_shard2_replica_n2] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1589810906308542464
[junit4] 2> 605997 INFO (searcherExecutor-1932-thread-1-processing-n:127.0.0.1:37285_solr x:halfdeletedcollection_shard2_replica_n2 s:shard2 c:halfdeletedcollection r:core_node4) [n:127.0.0.1:37285_solr c:halfdeletedcollection s:shard2 r:core_node4 x:halfdeletedcollection_shard2_replica_n2] o.a.s.c.SolrCore [halfdeletedcollection_shard2_replica_n2] Registered new searcher Searcher@1e62a6b[halfdeletedcollection_shard2_replica_n2] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 605999 INFO (zkCallback-935-thread-1-processing-n:127.0.0.1:43399_solr) [n:127.0.0.1:43399_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/halfdeletedcollection/state.json] for collection [halfdeletedcollection] has occurred - updating... (live nodes size: [4])
[junit4] 2> 605999 INFO (zkCallback-935-thread-2-processing-n:127.0.0.1:43399_solr) [n:127.0.0.1:43399_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/halfdeletedcollection/state.json] for collection [halfdeletedcollection] has occurred - updating... (live nodes size: [4])
[junit4] 2> 606000 INFO (zkCallback-950-thread-2-processing-n:127.0.0.1:37285_solr) [n:127.0.0.1:37285_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/halfdeletedcollection/state.json] for collection [halfdeletedcollection] has occurred - updating... (live nodes size: [4])
[junit4] 2> 606000 INFO (zkCallback-950-thread-1-processing-n:127.0.0.1:37285_solr) [n:127.0.0.1:37285_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/halfdeletedcollection/state.json] for collection [halfdeletedcollection] has occurred - updating... (live nodes size: [4])
[junit4] 2> 606001 INFO (qtp15452052-4490) [n:127.0.0.1:37285_solr c:halfdeletedcollection s:shard2 r:core_node4 x:halfdeletedcollection_shard2_replica_n2] o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue.
[junit4] 2> 606002 INFO (qtp15452052-4490) [n:127.0.0.1:37285_solr c:halfdeletedcollection s:shard2 r:core_node4 x:halfdeletedcollection_shard2_replica_n2] o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync
[junit4] 2> 606002 INFO (qtp15452052-4490) [n:127.0.0.1:37285_solr c:halfdeletedcollection s:shard2 r:core_node4 x:halfdeletedcollection_shard2_replica_n2] o.a.s.c.SyncStrategy Sync replicas to https://127.0.0.1:37285/solr/halfdeletedcollection_shard2_replica_n2/
[junit4] 2> 606002 INFO (qtp15452052-4490) [n:127.0.0.1:37285_solr c:halfdeletedcollection s:shard2 r:core_node4 x:halfdeletedcollection_shard2_replica_n2] o.a.s.c.SyncStrategy Sync Success - now sync replicas to me
[junit4] 2> 606002 INFO (qtp15452052-4490) [n:127.0.0.1:37285_solr c:halfdeletedcollection s:shard2 r:core_node4 x:halfdeletedcollection_shard2_replica_n2] o.a.s.c.SyncStrategy https://127.0.0.1:37285/solr/halfdeletedcollection_shard2_replica_n2/ has no replicas
[junit4] 2> 606002 INFO (qtp15452052-4490) [n:127.0.0.1:37285_solr c:halfdeletedcollection s:shard2 r:core_node4 x:halfdeletedcollection_shard2_replica_n2] o.a.s.c.ShardLeaderElectionContext Found all replicas participating in election, clear LIR
[junit4] 2> 606006 INFO (qtp15452052-4490) [n:127.0.0.1:37285_solr c:halfdeletedcollection s:shard2 r:core_node4 x:halfdeletedcollection_shard2_replica_n2] o.a.s.c.ShardLeaderElectionContext I am the new leader: https://127.0.0.1:37285/solr/halfdeletedcollection_shard2_replica_n2/ shard2
[junit4] 2> 606046 INFO (qtp15097313-4476) [n:127.0.0.1:43399_solr c:halfdeletedcollection s:shard1 r:core_node3 x:halfdeletedcollection_shard1_replica_n1] o.a.s.c.ZkController I am the leader, no recovery necessary
[junit4] 2> 606048 INFO (qtp15097313-4476) [n:127.0.0.1:43399_solr c:halfdeletedcollection s:shard1 r:core_node3 x:halfdeletedcollection_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=halfdeletedcollection_shard1_replica_n1&action=CREATE&numShards=2&collection=halfdeletedcollection&shard=shard1&wt=javabin&version=2&replicaType=NRT} status=0 QTime=1861
[junit4] 2> 606148 INFO (zkCallback-935-thread-1-processing-n:127.0.0.1:43399_solr) [n:127.0.0.1:43399_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/halfdeletedcollection/state.json] for collection [halfdeletedcollection] has occurred - updating... (live nodes size: [4])
[junit4] 2> 606148 INFO (zkCallback-950-thread-1-processing-n:127.0.0.1:37285_solr) [n:127.0.0.1:37285_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/halfdeletedcollection/state.json] for collection [halfdeletedcollection] has occurred - updating... (live nodes size: [4])
[junit4] 2> 606148 INFO (zkCallback-935-thread-2-processing-n:127.0.0.1:43399_solr) [n:127.0.0.1:43399_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/halfdeletedcollection/state.json] for collection [halfdeletedcollection] has occurred - updating... (live nodes size: [4])
[junit4] 2> 606148 INFO (zkCallback-950-thread-2-processing-n:127.0.0.1:37285_solr) [n:127.0.0.1:37285_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/halfdeletedcollection/state.json] for collection [halfdeletedcollection] has occurred - updating... (live nodes size: [4])
[junit4] 2> 606157 INFO (qtp15452052-4490) [n:127.0.0.1:37285_solr c:halfdeletedcollection s:shard2 r:core_node4 x:halfdeletedcollection_shard2_replica_n2] o.a.s.c.ZkController I am the leader, no recovery necessary
[junit4] 2> 606160 INFO (qtp15452052-4490) [n:127.0.0.1:37285_solr c:halfdeletedcollection s:shard2 r:core_node4 x:halfdeletedcollection_shard2_replica_n2] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={qt=/admin/cores&coreNodeName=core_node4&collection.configName=conf&newCollection=true&name=halfdeletedcollection_shard2_replica_n2&action=CREATE&numShards=2&collection=halfdeletedcollection&shard=shard2&wt=javabin&version=2&replicaType=NRT} status=0 QTime=1964
[junit4] 2> 606165 INFO (qtp23356785-4487) [n:127.0.0.1:35637_solr ] o.a.s.h.a.CollectionsHandler Wait for new collection to be active for at most 30 seconds. Check all shard replicas
[junit4] 2> 606264 INFO (zkCallback-950-thread-2-processing-n:127.0.0.1:37285_solr) [n:127.0.0.1:37285_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/halfdeletedcollection/state.json] for collection [halfdeletedcollection] has occurred - updating... (live nodes size: [4])
[junit4] 2> 606264 INFO (zkCallback-935-thread-1-processing-n:127.0.0.1:43399_solr) [n:127.0.0.1:43399_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/halfdeletedcollection/state.json] for collection [halfdeletedcollection] has occurred - updating... (live nodes size: [4])
[junit4] 2> 606264 INFO (zkCallback-935-thread-2-processing-n:127.0.0.1:43399_solr) [n:127.0.0.1:43399_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/halfdeletedcollection/state.json] for collection [halfdeletedcollection] has occurred - updating... (live nodes size: [4])
[junit4] 2> 606264 INFO (zkCallback-950-thread-1-processing-n:127.0.0.1:37285_solr) [n:127.0.0.1:37285_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/halfdeletedcollection/state.json] for collection [halfdeletedcollection] has occurred - updating... (live nodes size: [4])
[junit4] 2> 607166 INFO (qtp23356785-4487) [n:127.0.0.1:35637_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={replicationFactor=1&collection.configName=conf&name=halfdeletedcollection&nrtReplicas=1&action=CREATE&numShards=2&wt=javabin&version=2} status=0 QTime=3401
[junit4] 2> 607168 INFO (qtp23356785-4483) [n:127.0.0.1:35637_solr ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :list with params action=LIST&wt=javabin&version=2 and sendToOCPQueue=true
[junit4] 2> 607168 INFO (qtp23356785-4483) [n:127.0.0.1:35637_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> 607169 INFO (TEST-CollectionsAPIDistributedZkTest.deletePartiallyCreatedCollection-seed#[1C0E541453B71943]) [ ] o.a.s.SolrTestCaseJ4 ###Ending deletePartiallyCreatedCollection
[junit4] 2> 607208 INFO (TEST-CollectionsAPIDistributedZkTest.testCollectionReload-seed#[1C0E541453B71943]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testCollectionReload
[junit4] 2> 607209 INFO (TEST-CollectionsAPIDistributedZkTest.testCollectionReload-seed#[1C0E541453B71943]) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (4)
[junit4] 2> 607210 INFO (qtp23356785-4487) [n:127.0.0.1:35637_solr ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :delete with params name=halfdeletedcollection&action=DELETE&wt=javabin&version=2 and sendToOCPQueue=true
[junit4] 2> 607212 INFO (OverseerCollectionConfigSetProcessor-99363181042270219-127.0.0.1:35637_solr-n_0000000000) [n:127.0.0.1:35637_solr ] o.a.s.c.OverseerTaskQueue Response ZK path: /overseer/collection-queue-work/qnr-0000000010 doesn't exist. Requestor may have disconnected from ZooKeeper
[junit4] 2> 607212 INFO (OverseerThreadFactory-1913-thread-5-processing-n:127.0.0.1:35637_solr) [n:127.0.0.1:35637_solr ] o.a.s.c.a.c.OverseerCollectionMessageHandler Executing Collection Cmd : action=UNLOAD&deleteInstanceDir=true&deleteDataDir=true
[junit4] 2> 607215 INFO (qtp15097313-4470) [n:127.0.0.1:43399_solr ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.core.halfdeletedcollection.shard1.replica_n1, tag=null
[junit4] 2> 607215 INFO (qtp15452052-4485) [n:127.0.0.1:37285_solr ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.core.halfdeletedcollection.shard2.replica_n2, tag=null
[junit4] 2> 607216 INFO (qtp15097313-4470) [n:127.0.0.1:43399_solr ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@1320df7: rootName = null, domain = solr.core.halfdeletedcollection.shard1.replica_n1, service url = null, agent id = null] for registry solr.core.halfdeletedcollection.shard1.replica_n1 / com.codahale.metrics.MetricRegistry@1047581
[junit4] 2> 607216 INFO (qtp15452052-4485) [n:127.0.0.1:37285_solr ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@140b2fc: rootName = null, domain = solr.core.halfdeletedcollection.shard2.replica_n2, service url = null, agent id = null] for registry solr.core.halfdeletedc
[...truncated too long message...]
ted live nodes from ZooKeeper... (3) -> (2)
[junit4] 2> 691732 INFO (zkCallback-978-thread-2-processing-n:127.0.0.1:43399_solr) [n:127.0.0.1:43399_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (2)
[junit4] 2> 691732 INFO (zkCallback-947-thread-3-processing-n:127.0.0.1:35637_solr) [n:127.0.0.1:35637_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (2)
[junit4] 2> 691733 INFO (jetty-closer-916-thread-2) [ ] o.a.s.c.ZkController Remove node as live in ZooKeeper:/live_nodes/127.0.0.1:35637_solr
[junit4] 2> 691734 INFO (jetty-closer-916-thread-2) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.cluster, tag=null
[junit4] 2> 691734 INFO (zkCallback-947-thread-1-processing-n:127.0.0.1:35637_solr) [n:127.0.0.1:35637_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (1)
[junit4] 2> 691734 INFO (zkCallback-978-thread-2-processing-n:127.0.0.1:43399_solr) [n:127.0.0.1:43399_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (1)
[junit4] 2> 691734 INFO (zkCallback-950-thread-2-processing-n:127.0.0.1:37285_solr) [n:127.0.0.1:37285_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (1)
[junit4] 2> 691736 INFO (jetty-closer-916-thread-4) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@48eff2{/solr,null,UNAVAILABLE}
[junit4] 2> 691737 INFO (jetty-closer-916-thread-4) [ ] o.e.j.s.session Stopped scavenging
[junit4] 2> 691738 INFO (jetty-closer-916-thread-2) [ ] o.a.s.c.Overseer Overseer (id=99363181042270219-127.0.0.1:35637_solr-n_0000000000) closing
[junit4] 2> 691738 INFO (OverseerStateUpdate-99363181042270219-127.0.0.1:35637_solr-n_0000000000) [n:127.0.0.1:35637_solr ] o.a.s.c.Overseer Overseer Loop exiting : 127.0.0.1:35637_solr
[junit4] 2> 691754 INFO (jetty-closer-916-thread-3) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jetty, tag=null
[junit4] 2> 691754 INFO (jetty-closer-916-thread-3) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@188066e: rootName = null, domain = solr.jetty, service url = null, agent id = null] for registry solr.jetty / com.codahale.metrics.MetricRegistry@da3997
[junit4] 2> 691756 INFO (jetty-closer-916-thread-3) [ ] o.a.s.c.ZkController Remove node as live in ZooKeeper:/live_nodes/127.0.0.1:43399_solr
[junit4] 2> 691756 WARN (OverseerAutoScalingTriggerThread-99363181042270219-127.0.0.1:35637_solr-n_0000000000) [n:127.0.0.1:35637_solr ] o.a.s.c.a.OverseerTriggerThread OverseerTriggerThread woken up but we are closed, exiting.
[junit4] 2> 691758 INFO (jetty-closer-916-thread-3) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.cluster, tag=null
[junit4] 2> 691762 INFO (zkCallback-978-thread-2-processing-n:127.0.0.1:43399_solr) [n:127.0.0.1:43399_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (0)
[junit4] 2> 691762 INFO (zkCallback-978-thread-1-processing-n:127.0.0.1:43399_solr) [n:127.0.0.1:43399_solr ] o.a.s.c.OverseerElectionContext I am going to be the leader 127.0.0.1:43399_solr
[junit4] 2> 691766 INFO (coreCloseExecutor-2104-thread-1) [n:127.0.0.1:43399_solr c:awhollynewcollection_0 s:shard2 r:core_node5 x:awhollynewcollection_0_shard2_replica_n2] o.a.s.c.SolrCore [awhollynewcollection_0_shard2_replica_n2] CLOSING SolrCore org.apache.solr.core.SolrCore@9d4d93
[junit4] 2> 691766 INFO (coreCloseExecutor-2104-thread-1) [n:127.0.0.1:43399_solr c:awhollynewcollection_0 s:shard2 r:core_node5 x:awhollynewcollection_0_shard2_replica_n2] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.core.awhollynewcollection_0.shard2.replica_n2, tag=10309011
[junit4] 2> 691766 INFO (coreCloseExecutor-2104-thread-1) [n:127.0.0.1:43399_solr c:awhollynewcollection_0 s:shard2 r:core_node5 x:awhollynewcollection_0_shard2_replica_n2] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@b0a095: rootName = null, domain = solr.core.awhollynewcollection_0.shard2.replica_n2, service url = null, agent id = null] for registry solr.core.awhollynewcollection_0.shard2.replica_n2 / com.codahale.metrics.MetricRegistry@5b4db9
[junit4] 2> 691815 INFO (coreCloseExecutor-2104-thread-1) [n:127.0.0.1:43399_solr c:awhollynewcollection_0 s:shard2 r:core_node5 x:awhollynewcollection_0_shard2_replica_n2] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.collection.awhollynewcollection_0.shard2.leader, tag=10309011
[junit4] 2> 691818 INFO (jetty-closer-916-thread-3) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@1c35641{/solr,null,UNAVAILABLE}
[junit4] 2> 691818 INFO (jetty-closer-916-thread-3) [ ] o.e.j.s.session Stopped scavenging
[junit4] 2> 693258 WARN (zkCallback-947-thread-1-processing-n:127.0.0.1:35637_solr) [n:127.0.0.1:35637_solr ] o.a.s.c.c.ZkStateReader ZooKeeper watch triggered, but Solr cannot talk to ZK: [KeeperErrorCode = Session expired for /live_nodes]
[junit4] 2> 693259 INFO (jetty-closer-916-thread-2) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@1b6a7e{/solr,null,UNAVAILABLE}
[junit4] 2> 693260 INFO (jetty-closer-916-thread-2) [ ] o.e.j.s.session Stopped scavenging
[junit4] 2> 693262 ERROR (SUITE-CollectionsAPIDistributedZkTest-seed#[1C0E541453B71943]-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> 693262 INFO (SUITE-CollectionsAPIDistributedZkTest-seed#[1C0E541453B71943]-worker) [ ] o.a.s.c.ZkTestServer connecting to 127.0.0.1:34027 34027
[junit4] 2> 698097 INFO (Thread-1293) [ ] o.a.s.c.ZkTestServer connecting to 127.0.0.1:34027 34027
[junit4] 2> 698099 WARN (Thread-1293) [ ] o.a.s.c.ZkTestServer Watch limit violations:
[junit4] 2> Maximum concurrent create/delete watches above limit:
[junit4] 2>
[junit4] 2> 25 /solr/aliases.json
[junit4] 2> 22 /solr/configs/conf
[junit4] 2> 5 /solr/security.json
[junit4] 2> 5 /solr/configs/conf2
[junit4] 2>
[junit4] 2> Maximum concurrent data watches above limit:
[junit4] 2>
[junit4] 2> 56 /solr/collections/addReplicaColl/state.json
[junit4] 2> 36 /solr/collections/nodes_used_collection/state.json
[junit4] 2> 26 /solr/collections/reloaded_collection/state.json
[junit4] 2> 25 /solr/clusterprops.json
[junit4] 2> 25 /solr/clusterstate.json
[junit4] 2> 21 /solr/collections/awhollynewcollection_0/state.json
[junit4] 2> 16 /solr/collections/halfdeletedcollection/state.json
[junit4] 2> 15 /solr/collections/acollectionafterbaddelete/state.json
[junit4] 2> 10 /solr/collections/onlyinzk/state.json
[junit4] 2> 5 /solr/collections/halfcollectionblocker/state.json
[junit4] 2> 5 /solr/collections/created_and_deleted/state.json
[junit4] 2> 5 /solr/collections/halfcollectionblocker2/state.json
[junit4] 2> 5 /solr/collections/withconfigset2/state.json
[junit4] 2> 4 /solr/collections/halfcollection/state.json
[junit4] 2> 2 /solr/overseer_elect/election/99363181042270219-127.0.0.1:35637_solr-n_0000000000
[junit4] 2> 2 /solr/overseer_elect/election/99363181042270220-127.0.0.1:37285_solr-n_0000000001
[junit4] 2> 2 /solr/collections/addReplicaColl/leader_elect/shard1/election/99363181042270220-core_node5-n_0000000000
[junit4] 2> 2 /solr/overseer_elect/election/99363181042270216-127.0.0.1:33819_solr-n_0000000002
[junit4] 2> 2 /solr/collections/addReplicaColl/leader_elect/shard1/election/99363181042270225-core_node10-n_0000000002
[junit4] 2>
[junit4] 2> Maximum concurrent children watches above limit:
[junit4] 2>
[junit4] 2> 356 /solr/collections
[junit4] 2> 39 /solr/live_nodes
[junit4] 2>
[junit4] 2> NOTE: leaving temporary files on disk at: /home/jenkins/workspace/Lucene-Solr-7.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.api.collections.CollectionsAPIDistributedZkTest_1C0E541453B71943-001
[junit4] 2> NOTE: test params are: codec=Asserting(Lucene70): {id=Lucene50(blocksize=128)}, docValues:{}, maxPointsInLeafNode=392, maxMBSortInHeap=6.21916839018814, sim=RandomSimilarity(queryNorm=true): {}, locale=es-CR, timezone=America/Cayman
[junit4] 2> NOTE: Linux 4.13.0-26-generic i386/Oracle Corporation 1.8.0_144 (32-bit)/cpus=8,threads=1,free=73682696,total=163971072
[junit4] 2> NOTE: All tests run in this JVM: [ClassificationUpdateProcessorTest, ShardRoutingCustomTest, TestSolrCloudWithHadoopAuthPlugin, TestPivotHelperCode, HdfsCollectionsAPIDistributedZkTest, TestCoreBackup, TestSearchPerf, ZkControllerTest, DistributedIntervalFacetingTest, AddReplicaTest, TestFieldCacheReopen, TestObjectReleaseTracker, TestDistribDocBasedVersion, TestFieldResource, TestReqParamsAPI, TestStressCloudBlindAtomicUpdates, TestCollectionAPI, CurrencyFieldTypeTest, ComputePlanActionTest, DistributedFacetPivotSmallTest, BadCopyFieldTest, TestSchemaNameResource, HttpTriggerListenerTest, SolrShardReporterTest, SpatialHeatmapFacetsTest, CloudMLTQParserTest, BigEndianAscendingWordDeserializerTest, SystemInfoHandlerTest, RequiredFieldsTest, HdfsRestartWhileUpdatingTest, TestLRUCache, RollingRestartTest, SolrCoreTest, TestInPlaceUpdatesDistrib, XsltUpdateRequestHandlerTest, TestManagedStopFilterFactory, SearchHandlerTest, PathHierarchyTokenizerFactoryTest, TestConfigSetImmutable, TestLegacyTerms, TestMacroExpander, TestDynamicFieldCollectionResource, QueryElevationComponentTest, CollectionsAPIDistributedZkTest]
[junit4] Completed [183/767 (1!)] on J1 in 101.42s, 19 tests, 1 error <<< FAILURES!
[...truncated 45750 lines...]