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 2017/10/01 20:23:16 UTC
[JENKINS] Lucene-Solr-7.0-Linux (32bit/jdk1.8.0_144) - Build # 403
- Unstable!
Build: https://jenkins.thetaphi.de/job/Lucene-Solr-7.0-Linux/403/
Java: 32bit/jdk1.8.0_144 -server -XX:+UseParallelGC
1 tests failed.
FAILED: org.apache.solr.cloud.CollectionsAPIDistributedZkTest.testCollectionsAPI
Error Message:
Error from server at http://127.0.0.1:41577/solr/awhollynewcollection_0_shard4_replica_n1: ClusterState says we are the leader (http://127.0.0.1:41577/solr/awhollynewcollection_0_shard4_replica_n1), but locally we don't think so. Request came from null
Stack Trace:
org.apache.solr.client.solrj.impl.CloudSolrClient$RouteException: Error from server at http://127.0.0.1:41577/solr/awhollynewcollection_0_shard4_replica_n1: ClusterState says we are the leader (http://127.0.0.1:41577/solr/awhollynewcollection_0_shard4_replica_n1), but locally we don't think so. Request came from null
at __randomizedtesting.SeedInfo.seed([22F645446B8A6553:6A8331F06DB94AC6]:0)
at org.apache.solr.client.solrj.impl.CloudSolrClient.directUpdate(CloudSolrClient.java:539)
at org.apache.solr.client.solrj.impl.CloudSolrClient.sendRequest(CloudSolrClient.java:993)
at org.apache.solr.client.solrj.impl.CloudSolrClient.requestWithRetryOnStaleState(CloudSolrClient.java:862)
at org.apache.solr.client.solrj.impl.CloudSolrClient.request(CloudSolrClient.java:793)
at org.apache.solr.client.solrj.SolrRequest.process(SolrRequest.java:178)
at org.apache.solr.client.solrj.request.UpdateRequest.commit(UpdateRequest.java:233)
at org.apache.solr.cloud.CollectionsAPIDistributedZkTest.testCollectionsAPI(CollectionsAPIDistributedZkTest.java:458)
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:1713)
at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:907)
at com.carrotsearch.randomizedtesting.RandomizedRunner$9.evaluate(RandomizedRunner.java:943)
at com.carrotsearch.randomizedtesting.RandomizedRunner$10.evaluate(RandomizedRunner.java:957)
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:916)
at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:802)
at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:852)
at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:863)
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 http://127.0.0.1:41577/solr/awhollynewcollection_0_shard4_replica_n1: ClusterState says we are the leader (http://127.0.0.1:41577/solr/awhollynewcollection_0_shard4_replica_n1), but locally we don't think so. Request came from null
at org.apache.solr.client.solrj.impl.HttpSolrClient.executeMethod(HttpSolrClient.java:627)
at org.apache.solr.client.solrj.impl.HttpSolrClient.request(HttpSolrClient.java:253)
at org.apache.solr.client.solrj.impl.HttpSolrClient.request(HttpSolrClient.java:242)
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:516)
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 11969 lines...]
[junit4] Suite: org.apache.solr.cloud.CollectionsAPIDistributedZkTest
[junit4] 2> Creating dataDir: /home/jenkins/workspace/Lucene-Solr-7.0-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.CollectionsAPIDistributedZkTest_22F645446B8A6553-001/init-core-data-001
[junit4] 2> 1294243 WARN (SUITE-CollectionsAPIDistributedZkTest-seed#[22F645446B8A6553]-worker) [ ] o.a.s.SolrTestCaseJ4 startTrackingSearchers: numOpens=9 numCloses=9
[junit4] 2> 1294243 INFO (SUITE-CollectionsAPIDistributedZkTest-seed#[22F645446B8A6553]-worker) [ ] o.a.s.SolrTestCaseJ4 Using PointFields (NUMERIC_POINTS_SYSPROP=true) w/NUMERIC_DOCVALUES_SYSPROP=false
[junit4] 2> 1294244 INFO (SUITE-CollectionsAPIDistributedZkTest-seed#[22F645446B8A6553]-worker) [ ] o.a.s.SolrTestCaseJ4 Randomized ssl (false) and clientAuth (true) via: @org.apache.solr.util.RandomizeSSL(reason=, ssl=NaN, value=NaN, clientAuth=NaN)
[junit4] 2> 1294245 INFO (SUITE-CollectionsAPIDistributedZkTest-seed#[22F645446B8A6553]-worker) [ ] o.a.s.c.MiniSolrCloudCluster Starting cluster of 4 servers in /home/jenkins/workspace/Lucene-Solr-7.0-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.CollectionsAPIDistributedZkTest_22F645446B8A6553-001/tempDir-001
[junit4] 2> 1294245 INFO (SUITE-CollectionsAPIDistributedZkTest-seed#[22F645446B8A6553]-worker) [ ] o.a.s.c.ZkTestServer STARTING ZK TEST SERVER
[junit4] 2> 1294245 INFO (Thread-3876) [ ] o.a.s.c.ZkTestServer client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 1294245 INFO (Thread-3876) [ ] o.a.s.c.ZkTestServer Starting server
[junit4] 2> 1294246 ERROR (Thread-3876) [ ] 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> 1294345 INFO (SUITE-CollectionsAPIDistributedZkTest-seed#[22F645446B8A6553]-worker) [ ] o.a.s.c.ZkTestServer start zk server on port:46533
[junit4] 2> 1294349 INFO (jetty-launcher-1432-thread-2) [ ] o.e.j.s.Server jetty-9.3.14.v20161028
[junit4] 2> 1294349 INFO (jetty-launcher-1432-thread-3) [ ] o.e.j.s.Server jetty-9.3.14.v20161028
[junit4] 2> 1294349 INFO (jetty-launcher-1432-thread-1) [ ] o.e.j.s.Server jetty-9.3.14.v20161028
[junit4] 2> 1294349 INFO (jetty-launcher-1432-thread-4) [ ] o.e.j.s.Server jetty-9.3.14.v20161028
[junit4] 2> 1294350 INFO (jetty-launcher-1432-thread-4) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@16d6b20{/solr,null,AVAILABLE}
[junit4] 2> 1294350 INFO (jetty-launcher-1432-thread-2) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@5710ad{/solr,null,AVAILABLE}
[junit4] 2> 1294351 INFO (jetty-launcher-1432-thread-4) [ ] o.e.j.s.AbstractConnector Started ServerConnector@1b952e3{HTTP/1.1,[http/1.1]}{127.0.0.1:41577}
[junit4] 2> 1294351 INFO (jetty-launcher-1432-thread-3) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@1803eec{/solr,null,AVAILABLE}
[junit4] 2> 1294351 INFO (jetty-launcher-1432-thread-4) [ ] o.e.j.s.Server Started @1295980ms
[junit4] 2> 1294351 INFO (jetty-launcher-1432-thread-4) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=41577}
[junit4] 2> 1294351 ERROR (jetty-launcher-1432-thread-4) [ ] o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 1294351 INFO (jetty-launcher-1432-thread-4) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr™ version 7.0.1
[junit4] 2> 1294351 INFO (jetty-launcher-1432-thread-4) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 1294351 INFO (jetty-launcher-1432-thread-4) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null, Default config dir: null
[junit4] 2> 1294351 INFO (jetty-launcher-1432-thread-4) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2017-10-01T19:48:45.936Z
[junit4] 2> 1294352 INFO (jetty-launcher-1432-thread-1) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@1adf4bc{/solr,null,AVAILABLE}
[junit4] 2> 1294352 INFO (jetty-launcher-1432-thread-3) [ ] o.e.j.s.AbstractConnector Started ServerConnector@c82d0{HTTP/1.1,[http/1.1]}{127.0.0.1:43357}
[junit4] 2> 1294352 INFO (jetty-launcher-1432-thread-3) [ ] o.e.j.s.Server Started @1295981ms
[junit4] 2> 1294352 INFO (jetty-launcher-1432-thread-3) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=43357}
[junit4] 2> 1294352 INFO (jetty-launcher-1432-thread-2) [ ] o.e.j.s.AbstractConnector Started ServerConnector@13e79c5{HTTP/1.1,[http/1.1]}{127.0.0.1:40241}
[junit4] 2> 1294352 INFO (jetty-launcher-1432-thread-2) [ ] o.e.j.s.Server Started @1295981ms
[junit4] 2> 1294352 ERROR (jetty-launcher-1432-thread-3) [ ] o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 1294352 INFO (jetty-launcher-1432-thread-2) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=40241}
[junit4] 2> 1294352 INFO (jetty-launcher-1432-thread-3) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr™ version 7.0.1
[junit4] 2> 1294352 INFO (jetty-launcher-1432-thread-3) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 1294352 ERROR (jetty-launcher-1432-thread-2) [ ] o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 1294352 INFO (jetty-launcher-1432-thread-3) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null, Default config dir: null
[junit4] 2> 1294352 INFO (jetty-launcher-1432-thread-2) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr™ version 7.0.1
[junit4] 2> 1294352 INFO (jetty-launcher-1432-thread-3) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2017-10-01T19:48:45.937Z
[junit4] 2> 1294352 INFO (jetty-launcher-1432-thread-2) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 1294352 INFO (jetty-launcher-1432-thread-2) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null, Default config dir: null
[junit4] 2> 1294352 INFO (jetty-launcher-1432-thread-2) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2017-10-01T19:48:45.937Z
[junit4] 2> 1294353 INFO (jetty-launcher-1432-thread-1) [ ] o.e.j.s.AbstractConnector Started ServerConnector@590308{HTTP/1.1,[http/1.1]}{127.0.0.1:42951}
[junit4] 2> 1294353 INFO (jetty-launcher-1432-thread-1) [ ] o.e.j.s.Server Started @1295982ms
[junit4] 2> 1294353 INFO (jetty-launcher-1432-thread-1) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=42951}
[junit4] 2> 1294354 ERROR (jetty-launcher-1432-thread-1) [ ] o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 1294354 INFO (jetty-launcher-1432-thread-4) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 1294354 INFO (jetty-launcher-1432-thread-1) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr™ version 7.0.1
[junit4] 2> 1294354 INFO (jetty-launcher-1432-thread-1) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 1294354 INFO (jetty-launcher-1432-thread-1) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null, Default config dir: null
[junit4] 2> 1294354 INFO (jetty-launcher-1432-thread-1) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2017-10-01T19:48:45.939Z
[junit4] 2> 1294358 INFO (jetty-launcher-1432-thread-2) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 1294358 INFO (jetty-launcher-1432-thread-1) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 1294359 INFO (jetty-launcher-1432-thread-3) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 1294365 INFO (jetty-launcher-1432-thread-4) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:46533/solr
[junit4] 2> 1294369 INFO (jetty-launcher-1432-thread-2) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:46533/solr
[junit4] 2> 1294369 INFO (jetty-launcher-1432-thread-1) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:46533/solr
[junit4] 2> 1294369 INFO (jetty-launcher-1432-thread-3) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:46533/solr
[junit4] 2> 1294371 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 0x15ed97bd8860005, 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> 1294383 INFO (jetty-launcher-1432-thread-3) [n:127.0.0.1:43357_solr ] o.a.s.c.Overseer Overseer (id=null) closing
[junit4] 2> 1294383 INFO (jetty-launcher-1432-thread-3) [n:127.0.0.1:43357_solr ] o.a.s.c.OverseerElectionContext I am going to be the leader 127.0.0.1:43357_solr
[junit4] 2> 1294384 INFO (jetty-launcher-1432-thread-3) [n:127.0.0.1:43357_solr ] o.a.s.c.Overseer Overseer (id=98755367785594891-127.0.0.1:43357_solr-n_0000000000) starting
[junit4] 2> 1294387 INFO (jetty-launcher-1432-thread-3) [n:127.0.0.1:43357_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:43357_solr
[junit4] 2> 1294387 INFO (zkCallback-1453-thread-1-processing-n:127.0.0.1:43357_solr) [n:127.0.0.1:43357_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 1294411 INFO (jetty-launcher-1432-thread-4) [n:127.0.0.1:41577_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 1294411 INFO (jetty-launcher-1432-thread-1) [n:127.0.0.1:42951_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 1294412 INFO (jetty-launcher-1432-thread-2) [n:127.0.0.1:40241_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 1294412 INFO (jetty-launcher-1432-thread-4) [n:127.0.0.1:41577_solr ] o.a.s.c.Overseer Overseer (id=null) closing
[junit4] 2> 1294412 INFO (jetty-launcher-1432-thread-1) [n:127.0.0.1:42951_solr ] o.a.s.c.Overseer Overseer (id=null) closing
[junit4] 2> 1294412 INFO (jetty-launcher-1432-thread-2) [n:127.0.0.1:40241_solr ] o.a.s.c.Overseer Overseer (id=null) closing
[junit4] 2> 1294414 INFO (jetty-launcher-1432-thread-4) [n:127.0.0.1:41577_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:41577_solr
[junit4] 2> 1294417 INFO (zkCallback-1451-thread-1-processing-n:127.0.0.1:41577_solr) [n:127.0.0.1:41577_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
[junit4] 2> 1294421 INFO (zkCallback-1452-thread-1-processing-n:127.0.0.1:40241_solr) [n:127.0.0.1:40241_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
[junit4] 2> 1294421 INFO (zkCallback-1453-thread-1-processing-n:127.0.0.1:43357_solr) [n:127.0.0.1:43357_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
[junit4] 2> 1294422 INFO (jetty-launcher-1432-thread-1) [n:127.0.0.1:42951_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:42951_solr
[junit4] 2> 1294422 INFO (zkCallback-1454-thread-1-processing-n:127.0.0.1:42951_solr) [n:127.0.0.1:42951_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
[junit4] 2> 1294422 INFO (jetty-launcher-1432-thread-2) [n:127.0.0.1:40241_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:40241_solr
[junit4] 2> 1294422 INFO (zkCallback-1452-thread-1-processing-n:127.0.0.1:40241_solr) [n:127.0.0.1:40241_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (4)
[junit4] 2> 1294422 INFO (zkCallback-1454-thread-1-processing-n:127.0.0.1:42951_solr) [n:127.0.0.1:42951_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (4)
[junit4] 2> 1294423 INFO (zkCallback-1451-thread-1-processing-n:127.0.0.1:41577_solr) [n:127.0.0.1:41577_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (4)
[junit4] 2> 1294423 INFO (zkCallback-1453-thread-1-processing-n:127.0.0.1:43357_solr) [n:127.0.0.1:43357_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (4)
[junit4] 2> 1294475 INFO (jetty-launcher-1432-thread-3) [n:127.0.0.1:43357_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@197c0cb
[junit4] 2> 1294481 INFO (jetty-launcher-1432-thread-3) [n:127.0.0.1:43357_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@197c0cb
[junit4] 2> 1294481 INFO (jetty-launcher-1432-thread-3) [n:127.0.0.1:43357_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@197c0cb
[junit4] 2> 1294481 INFO (jetty-launcher-1432-thread-3) [n:127.0.0.1:43357_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /home/jenkins/workspace/Lucene-Solr-7.0-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.CollectionsAPIDistributedZkTest_22F645446B8A6553-001/tempDir-001/node3
[junit4] 2> 1294487 INFO (jetty-launcher-1432-thread-2) [n:127.0.0.1:40241_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@197c0cb
[junit4] 2> 1294495 INFO (jetty-launcher-1432-thread-2) [n:127.0.0.1:40241_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@197c0cb
[junit4] 2> 1294495 INFO (jetty-launcher-1432-thread-2) [n:127.0.0.1:40241_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@197c0cb
[junit4] 2> 1294496 INFO (jetty-launcher-1432-thread-2) [n:127.0.0.1:40241_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /home/jenkins/workspace/Lucene-Solr-7.0-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.CollectionsAPIDistributedZkTest_22F645446B8A6553-001/tempDir-001/node2
[junit4] 2> 1294567 INFO (jetty-launcher-1432-thread-4) [n:127.0.0.1:41577_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@197c0cb
[junit4] 2> 1294571 INFO (jetty-launcher-1432-thread-1) [n:127.0.0.1:42951_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@197c0cb
[junit4] 2> 1294574 INFO (jetty-launcher-1432-thread-4) [n:127.0.0.1:41577_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@197c0cb
[junit4] 2> 1294574 INFO (jetty-launcher-1432-thread-4) [n:127.0.0.1:41577_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@197c0cb
[junit4] 2> 1294574 INFO (jetty-launcher-1432-thread-4) [n:127.0.0.1:41577_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /home/jenkins/workspace/Lucene-Solr-7.0-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.CollectionsAPIDistributedZkTest_22F645446B8A6553-001/tempDir-001/node4
[junit4] 2> 1294580 INFO (jetty-launcher-1432-thread-1) [n:127.0.0.1:42951_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@197c0cb
[junit4] 2> 1294580 INFO (jetty-launcher-1432-thread-1) [n:127.0.0.1:42951_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@197c0cb
[junit4] 2> 1294581 INFO (jetty-launcher-1432-thread-1) [n:127.0.0.1:42951_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /home/jenkins/workspace/Lucene-Solr-7.0-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.CollectionsAPIDistributedZkTest_22F645446B8A6553-001/tempDir-001/node1
[junit4] 2> 1294632 INFO (SUITE-CollectionsAPIDistributedZkTest-seed#[22F645446B8A6553]-worker) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (4)
[junit4] 2> 1294632 INFO (SUITE-CollectionsAPIDistributedZkTest-seed#[22F645446B8A6553]-worker) [ ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:46533/solr ready
[junit4] 2> 1294653 INFO (TEST-CollectionsAPIDistributedZkTest.testDeleteNonExistentCollection-seed#[22F645446B8A6553]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testDeleteNonExistentCollection
[junit4] 2> 1294654 INFO (TEST-CollectionsAPIDistributedZkTest.testDeleteNonExistentCollection-seed#[22F645446B8A6553]) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (4)
[junit4] 2> 1294655 INFO (qtp22071740-11743) [n:127.0.0.1:42951_solr ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :delete with params name=unknown_collection&action=DELETE&wt=javabin&version=2 and sendToOCPQueue=true
[junit4] 2> 1294656 INFO (OverseerThreadFactory-4007-thread-1-processing-n:127.0.0.1:43357_solr) [n:127.0.0.1:43357_solr ] o.a.s.c.OverseerCollectionMessageHandler Executing Collection Cmd : action=UNLOAD&deleteInstanceDir=true&deleteDataDir=true
[junit4] 2> 1294657 ERROR (OverseerThreadFactory-4007-thread-1-processing-n:127.0.0.1:43357_solr) [n:127.0.0.1:43357_solr ] o.a.s.c.OverseerCollectionMessageHandler Collection: unknown_collection operation: delete failed:org.apache.solr.common.SolrException: Could not find collection : unknown_collection
[junit4] 2> at org.apache.solr.common.cloud.ClusterState.getCollection(ClusterState.java:109)
[junit4] 2> at org.apache.solr.cloud.OverseerCollectionMessageHandler.collectionCmd(OverseerCollectionMessageHandler.java:795)
[junit4] 2> at org.apache.solr.cloud.DeleteCollectionCmd.call(DeleteCollectionCmd.java:88)
[junit4] 2> at org.apache.solr.cloud.OverseerCollectionMessageHandler.processMessage(OverseerCollectionMessageHandler.java:227)
[junit4] 2> at org.apache.solr.cloud.OverseerTaskProcessor$Runner.run(OverseerTaskProcessor.java:464)
[junit4] 2> at org.apache.solr.common.util.ExecutorUtil$MDCAwareThreadPoolExecutor.lambda$execute$0(ExecutorUtil.java:188)
[junit4] 2> at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
[junit4] 2> at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
[junit4] 2> at java.lang.Thread.run(Thread.java:748)
[junit4] 2>
[junit4] 2> 1294663 INFO (qtp22071740-11743) [n:127.0.0.1:42951_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={name=unknown_collection&action=DELETE&wt=javabin&version=2} status=400 QTime=8
[junit4] 2> 1294664 INFO (qtp22071740-11746) [n:127.0.0.1:42951_solr ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :create with params replicationFactor=2&collection.configName=conf&name=acollectionafterbaddelete&nrtReplicas=2&action=CREATE&numShards=1&wt=javabin&version=2 and sendToOCPQueue=true
[junit4] 2> 1294665 INFO (OverseerThreadFactory-4007-thread-2-processing-n:127.0.0.1:43357_solr) [n:127.0.0.1:43357_solr ] o.a.s.c.CreateCollectionCmd Create collection acollectionafterbaddelete
[junit4] 2> 1294665 INFO (OverseerCollectionConfigSetProcessor-98755367785594891-127.0.0.1:43357_solr-n_0000000000) [n:127.0.0.1:43357_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> 1294768 INFO (OverseerStateUpdate-98755367785594891-127.0.0.1:43357_solr-n_0000000000) [n:127.0.0.1:43357_solr ] o.a.s.c.o.SliceMutator createReplica() {
[junit4] 2> "operation":"ADDREPLICA",
[junit4] 2> "collection":"acollectionafterbaddelete",
[junit4] 2> "shard":"shard1",
[junit4] 2> "core":"acollectionafterbaddelete_shard1_replica_n1",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"http://127.0.0.1:42951/solr",
[junit4] 2> "type":"NRT"}
[junit4] 2> 1294768 INFO (OverseerStateUpdate-98755367785594891-127.0.0.1:43357_solr-n_0000000000) [n:127.0.0.1:43357_solr ] o.a.s.c.o.SliceMutator createReplica() {
[junit4] 2> "operation":"ADDREPLICA",
[junit4] 2> "collection":"acollectionafterbaddelete",
[junit4] 2> "shard":"shard1",
[junit4] 2> "core":"acollectionafterbaddelete_shard1_replica_n2",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"http://127.0.0.1:41577/solr",
[junit4] 2> "type":"NRT"}
[junit4] 2> 1294970 INFO (qtp22071740-11724) [n:127.0.0.1:42951_solr ] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&coreNodeName=core_node1&collection.configName=conf&newCollection=true&name=acollectionafterbaddelete_shard1_replica_n1&action=CREATE&numShards=1&collection=acollectionafterbaddelete&shard=shard1&wt=javabin&version=2&replicaType=NRT
[junit4] 2> 1294970 INFO (qtp26363452-11735) [n:127.0.0.1:41577_solr ] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&coreNodeName=core_node2&collection.configName=conf&newCollection=true&name=acollectionafterbaddelete_shard1_replica_n2&action=CREATE&numShards=1&collection=acollectionafterbaddelete&shard=shard1&wt=javabin&version=2&replicaType=NRT
[junit4] 2> 1294970 INFO (qtp22071740-11724) [n:127.0.0.1:42951_solr ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores
[junit4] 2> 1294970 INFO (qtp26363452-11735) [n:127.0.0.1:41577_solr ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores
[junit4] 2> 1295073 INFO (zkCallback-1451-thread-1-processing-n:127.0.0.1:41577_solr) [n:127.0.0.1:41577_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/acollectionafterbaddelete/state.json] for collection [acollectionafterbaddelete] has occurred - updating... (live nodes size: [4])
[junit4] 2> 1295073 INFO (zkCallback-1454-thread-1-processing-n:127.0.0.1:42951_solr) [n:127.0.0.1:42951_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/acollectionafterbaddelete/state.json] for collection [acollectionafterbaddelete] has occurred - updating... (live nodes size: [4])
[junit4] 2> 1295073 INFO (zkCallback-1454-thread-2-processing-n:127.0.0.1:42951_solr) [n:127.0.0.1:42951_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/acollectionafterbaddelete/state.json] for collection [acollectionafterbaddelete] has occurred - updating... (live nodes size: [4])
[junit4] 2> 1295073 INFO (zkCallback-1451-thread-2-processing-n:127.0.0.1:41577_solr) [n:127.0.0.1:41577_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/acollectionafterbaddelete/state.json] for collection [acollectionafterbaddelete] has occurred - updating... (live nodes size: [4])
[junit4] 2> 1295985 INFO (qtp26363452-11735) [n:127.0.0.1:41577_solr c:acollectionafterbaddelete s:shard1 r:core_node2 x:acollectionafterbaddelete_shard1_replica_n2] o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.0.1
[junit4] 2> 1295986 INFO (qtp22071740-11724) [n:127.0.0.1:42951_solr c:acollectionafterbaddelete s:shard1 r:core_node1 x:acollectionafterbaddelete_shard1_replica_n1] o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.0.1
[junit4] 2> 1295991 INFO (qtp22071740-11724) [n:127.0.0.1:42951_solr c:acollectionafterbaddelete s:shard1 r:core_node1 x:acollectionafterbaddelete_shard1_replica_n1] o.a.s.s.IndexSchema [acollectionafterbaddelete_shard1_replica_n1] Schema name=minimal
[junit4] 2> 1295991 INFO (qtp26363452-11735) [n:127.0.0.1:41577_solr c:acollectionafterbaddelete s:shard1 r:core_node2 x:acollectionafterbaddelete_shard1_replica_n2] o.a.s.s.IndexSchema [acollectionafterbaddelete_shard1_replica_n2] Schema name=minimal
[junit4] 2> 1295993 INFO (qtp22071740-11724) [n:127.0.0.1:42951_solr c:acollectionafterbaddelete s:shard1 r:core_node1 x:acollectionafterbaddelete_shard1_replica_n1] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
[junit4] 2> 1295993 INFO (qtp26363452-11735) [n:127.0.0.1:41577_solr c:acollectionafterbaddelete s:shard1 r:core_node2 x:acollectionafterbaddelete_shard1_replica_n2] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
[junit4] 2> 1295993 INFO (qtp22071740-11724) [n:127.0.0.1:42951_solr c:acollectionafterbaddelete s:shard1 r:core_node1 x:acollectionafterbaddelete_shard1_replica_n1] o.a.s.c.CoreContainer Creating SolrCore 'acollectionafterbaddelete_shard1_replica_n1' using configuration from collection acollectionafterbaddelete, trusted=true
[junit4] 2> 1295993 INFO (qtp26363452-11735) [n:127.0.0.1:41577_solr c:acollectionafterbaddelete s:shard1 r:core_node2 x:acollectionafterbaddelete_shard1_replica_n2] o.a.s.c.CoreContainer Creating SolrCore 'acollectionafterbaddelete_shard1_replica_n2' using configuration from collection acollectionafterbaddelete, trusted=true
[junit4] 2> 1295993 INFO (qtp22071740-11724) [n:127.0.0.1:42951_solr c:acollectionafterbaddelete s:shard1 r:core_node1 x:acollectionafterbaddelete_shard1_replica_n1] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.core.acollectionafterbaddelete.shard1.replica_n1' (registry 'solr.core.acollectionafterbaddelete.shard1.replica_n1') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@197c0cb
[junit4] 2> 1295993 INFO (qtp26363452-11735) [n:127.0.0.1:41577_solr c:acollectionafterbaddelete s:shard1 r:core_node2 x:acollectionafterbaddelete_shard1_replica_n2] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.core.acollectionafterbaddelete.shard1.replica_n2' (registry 'solr.core.acollectionafterbaddelete.shard1.replica_n2') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@197c0cb
[junit4] 2> 1295993 INFO (qtp26363452-11735) [n:127.0.0.1:41577_solr c:acollectionafterbaddelete s:shard1 r:core_node2 x:acollectionafterbaddelete_shard1_replica_n2] o.a.s.c.SolrCore solr.RecoveryStrategy.Builder
[junit4] 2> 1295993 INFO (qtp22071740-11724) [n:127.0.0.1:42951_solr c:acollectionafterbaddelete s:shard1 r:core_node1 x:acollectionafterbaddelete_shard1_replica_n1] o.a.s.c.SolrCore solr.RecoveryStrategy.Builder
[junit4] 2> 1295994 INFO (qtp22071740-11724) [n:127.0.0.1:42951_solr c:acollectionafterbaddelete s:shard1 r:core_node1 x:acollectionafterbaddelete_shard1_replica_n1] o.a.s.c.SolrCore [[acollectionafterbaddelete_shard1_replica_n1] ] Opening new SolrCore at [/home/jenkins/workspace/Lucene-Solr-7.0-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.CollectionsAPIDistributedZkTest_22F645446B8A6553-001/tempDir-001/node1/acollectionafterbaddelete_shard1_replica_n1], dataDir=[/home/jenkins/workspace/Lucene-Solr-7.0-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.CollectionsAPIDistributedZkTest_22F645446B8A6553-001/tempDir-001/node1/acollectionafterbaddelete_shard1_replica_n1/data/]
[junit4] 2> 1295994 INFO (qtp26363452-11735) [n:127.0.0.1:41577_solr c:acollectionafterbaddelete s:shard1 r:core_node2 x:acollectionafterbaddelete_shard1_replica_n2] o.a.s.c.SolrCore [[acollectionafterbaddelete_shard1_replica_n2] ] Opening new SolrCore at [/home/jenkins/workspace/Lucene-Solr-7.0-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.CollectionsAPIDistributedZkTest_22F645446B8A6553-001/tempDir-001/node4/acollectionafterbaddelete_shard1_replica_n2], dataDir=[/home/jenkins/workspace/Lucene-Solr-7.0-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.CollectionsAPIDistributedZkTest_22F645446B8A6553-001/tempDir-001/node4/acollectionafterbaddelete_shard1_replica_n2/data/]
[junit4] 2> 1296031 INFO (qtp22071740-11724) [n:127.0.0.1:42951_solr c:acollectionafterbaddelete s:shard1 r:core_node1 x:acollectionafterbaddelete_shard1_replica_n1] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
[junit4] 2> 1296031 INFO (qtp22071740-11724) [n:127.0.0.1:42951_solr c:acollectionafterbaddelete s:shard1 r:core_node1 x:acollectionafterbaddelete_shard1_replica_n1] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 1296032 INFO (qtp22071740-11724) [n:127.0.0.1:42951_solr c:acollectionafterbaddelete s:shard1 r:core_node1 x:acollectionafterbaddelete_shard1_replica_n1] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 1296032 INFO (qtp22071740-11724) [n:127.0.0.1:42951_solr c:acollectionafterbaddelete s:shard1 r:core_node1 x:acollectionafterbaddelete_shard1_replica_n1] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 1296033 INFO (qtp22071740-11724) [n:127.0.0.1:42951_solr c:acollectionafterbaddelete s:shard1 r:core_node1 x:acollectionafterbaddelete_shard1_replica_n1] o.a.s.s.SolrIndexSearcher Opening [Searcher@199b0fe[acollectionafterbaddelete_shard1_replica_n1] main]
[junit4] 2> 1296033 INFO (qtp22071740-11724) [n:127.0.0.1:42951_solr c:acollectionafterbaddelete s:shard1 r:core_node1 x:acollectionafterbaddelete_shard1_replica_n1] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf
[junit4] 2> 1296033 INFO (qtp22071740-11724) [n:127.0.0.1:42951_solr c:acollectionafterbaddelete s:shard1 r:core_node1 x:acollectionafterbaddelete_shard1_replica_n1] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf
[junit4] 2> 1296034 INFO (qtp22071740-11724) [n:127.0.0.1:42951_solr c:acollectionafterbaddelete s:shard1 r:core_node1 x:acollectionafterbaddelete_shard1_replica_n1] o.a.s.h.ReplicationHandler Commits will be reserved for 10000
[junit4] 2> 1296034 INFO (qtp26363452-11735) [n:127.0.0.1:41577_solr c:acollectionafterbaddelete s:shard1 r:core_node2 x:acollectionafterbaddelete_shard1_replica_n2] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
[junit4] 2> 1296034 INFO (qtp26363452-11735) [n:127.0.0.1:41577_solr c:acollectionafterbaddelete s:shard1 r:core_node2 x:acollectionafterbaddelete_shard1_replica_n2] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 1296034 INFO (searcherExecutor-4016-thread-1-processing-n:127.0.0.1:42951_solr x:acollectionafterbaddelete_shard1_replica_n1 s:shard1 c:acollectionafterbaddelete r:core_node1) [n:127.0.0.1:42951_solr c:acollectionafterbaddelete s:shard1 r:core_node1 x:acollectionafterbaddelete_shard1_replica_n1] o.a.s.c.SolrCore [acollectionafterbaddelete_shard1_replica_n1] Registered new searcher Searcher@199b0fe[acollectionafterbaddelete_shard1_replica_n1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 1296034 INFO (qtp22071740-11724) [n:127.0.0.1:42951_solr c:acollectionafterbaddelete s:shard1 r:core_node1 x:acollectionafterbaddelete_shard1_replica_n1] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1580085886445420544
[junit4] 2> 1296035 INFO (qtp26363452-11735) [n:127.0.0.1:41577_solr c:acollectionafterbaddelete s:shard1 r:core_node2 x:acollectionafterbaddelete_shard1_replica_n2] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 1296035 INFO (qtp26363452-11735) [n:127.0.0.1:41577_solr c:acollectionafterbaddelete s:shard1 r:core_node2 x:acollectionafterbaddelete_shard1_replica_n2] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 1296037 INFO (qtp26363452-11735) [n:127.0.0.1:41577_solr c:acollectionafterbaddelete s:shard1 r:core_node2 x:acollectionafterbaddelete_shard1_replica_n2] o.a.s.s.SolrIndexSearcher Opening [Searcher@13730b1[acollectionafterbaddelete_shard1_replica_n2] main]
[junit4] 2> 1296037 INFO (qtp22071740-11724) [n:127.0.0.1:42951_solr c:acollectionafterbaddelete s:shard1 r:core_node1 x:acollectionafterbaddelete_shard1_replica_n1] o.a.s.c.ShardLeaderElectionContext Waiting until we see more replicas up for shard shard1: total=2 found=1 timeoutin=9999ms
[junit4] 2> 1296037 INFO (qtp26363452-11735) [n:127.0.0.1:41577_solr c:acollectionafterbaddelete s:shard1 r:core_node2 x:acollectionafterbaddelete_shard1_replica_n2] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf
[junit4] 2> 1296037 INFO (qtp26363452-11735) [n:127.0.0.1:41577_solr c:acollectionafterbaddelete s:shard1 r:core_node2 x:acollectionafterbaddelete_shard1_replica_n2] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf
[junit4] 2> 1296038 INFO (qtp26363452-11735) [n:127.0.0.1:41577_solr c:acollectionafterbaddelete s:shard1 r:core_node2 x:acollectionafterbaddelete_shard1_replica_n2] o.a.s.h.ReplicationHandler Commits will be reserved for 10000
[junit4] 2> 1296038 INFO (searcherExecutor-4017-thread-1-processing-n:127.0.0.1:41577_solr x:acollectionafterbaddelete_shard1_replica_n2 s:shard1 c:acollectionafterbaddelete r:core_node2) [n:127.0.0.1:41577_solr c:acollectionafterbaddelete s:shard1 r:core_node2 x:acollectionafterbaddelete_shard1_replica_n2] o.a.s.c.SolrCore [acollectionafterbaddelete_shard1_replica_n2] Registered new searcher Searcher@13730b1[acollectionafterbaddelete_shard1_replica_n2] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 1296038 INFO (qtp26363452-11735) [n:127.0.0.1:41577_solr c:acollectionafterbaddelete s:shard1 r:core_node2 x:acollectionafterbaddelete_shard1_replica_n2] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1580085886449614848
[junit4] 2> 1296138 INFO (zkCallback-1454-thread-1-processing-n:127.0.0.1:42951_solr) [n:127.0.0.1:42951_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/acollectionafterbaddelete/state.json] for collection [acollectionafterbaddelete] has occurred - updating... (live nodes size: [4])
[junit4] 2> 1296138 INFO (zkCallback-1454-thread-2-processing-n:127.0.0.1:42951_solr) [n:127.0.0.1:42951_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/acollectionafterbaddelete/state.json] for collection [acollectionafterbaddelete] has occurred - updating... (live nodes size: [4])
[junit4] 2> 1296138 INFO (zkCallback-1451-thread-1-processing-n:127.0.0.1:41577_solr) [n:127.0.0.1:41577_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/acollectionafterbaddelete/state.json] for collection [acollectionafterbaddelete] has occurred - updating... (live nodes size: [4])
[junit4] 2> 1296138 INFO (zkCallback-1451-thread-2-processing-n:127.0.0.1:41577_solr) [n:127.0.0.1:41577_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/acollectionafterbaddelete/state.json] for collection [acollectionafterbaddelete] has occurred - updating... (live nodes size: [4])
[junit4] 2> 1296537 INFO (qtp22071740-11724) [n:127.0.0.1:42951_solr c:acollectionafterbaddelete s:shard1 r:core_node1 x:acollectionafterbaddelete_shard1_replica_n1] o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue.
[junit4] 2> 1296537 INFO (qtp22071740-11724) [n:127.0.0.1:42951_solr c:acollectionafterbaddelete s:shard1 r:core_node1 x:acollectionafterbaddelete_shard1_replica_n1] o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync
[junit4] 2> 1296538 INFO (qtp22071740-11724) [n:127.0.0.1:42951_solr c:acollectionafterbaddelete s:shard1 r:core_node1 x:acollectionafterbaddelete_shard1_replica_n1] o.a.s.c.SyncStrategy Sync replicas to http://127.0.0.1:42951/solr/acollectionafterbaddelete_shard1_replica_n1/
[junit4] 2> 1296538 INFO (qtp22071740-11724) [n:127.0.0.1:42951_solr c:acollectionafterbaddelete s:shard1 r:core_node1 x:acollectionafterbaddelete_shard1_replica_n1] o.a.s.u.PeerSync PeerSync: core=acollectionafterbaddelete_shard1_replica_n1 url=http://127.0.0.1:42951/solr START replicas=[http://127.0.0.1:41577/solr/acollectionafterbaddelete_shard1_replica_n2/] nUpdates=100
[junit4] 2> 1296538 INFO (qtp22071740-11724) [n:127.0.0.1:42951_solr c:acollectionafterbaddelete s:shard1 r:core_node1 x:acollectionafterbaddelete_shard1_replica_n1] o.a.s.u.PeerSync PeerSync: core=acollectionafterbaddelete_shard1_replica_n1 url=http://127.0.0.1:42951/solr DONE. We have no versions. sync failed.
[junit4] 2> 1296539 INFO (qtp26363452-11725) [n:127.0.0.1:41577_solr c:acollectionafterbaddelete s:shard1 r:core_node2 x:acollectionafterbaddelete_shard1_replica_n2] o.a.s.c.S.Request [acollectionafterbaddelete_shard1_replica_n2] webapp=/solr path=/get params={distrib=false&qt=/get&fingerprint=false&getVersions=100&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 1296539 INFO (qtp22071740-11724) [n:127.0.0.1:42951_solr c:acollectionafterbaddelete s:shard1 r:core_node1 x:acollectionafterbaddelete_shard1_replica_n1] o.a.s.c.SyncStrategy Leader's attempt to sync with shard failed, moving to the next candidate
[junit4] 2> 1296539 INFO (qtp22071740-11724) [n:127.0.0.1:42951_solr c:acollectionafterbaddelete s:shard1 r:core_node1 x:acollectionafterbaddelete_shard1_replica_n1] o.a.s.c.ShardLeaderElectionContext We failed sync, but we have no versions - we can't sync in that case - we were active before, so become leader anyway
[junit4] 2> 1296539 INFO (qtp22071740-11724) [n:127.0.0.1:42951_solr c:acollectionafterbaddelete s:shard1 r:core_node1 x:acollectionafterbaddelete_shard1_replica_n1] o.a.s.c.ShardLeaderElectionContext Found all replicas participating in election, clear LIR
[junit4] 2> 1296540 INFO (qtp22071740-11724) [n:127.0.0.1:42951_solr c:acollectionafterbaddelete s:shard1 r:core_node1 x:acollectionafterbaddelete_shard1_replica_n1] o.a.s.c.ShardLeaderElectionContext I am the new leader: http://127.0.0.1:42951/solr/acollectionafterbaddelete_shard1_replica_n1/ shard1
[junit4] 2> 1296641 INFO (zkCallback-1454-thread-2-processing-n:127.0.0.1:42951_solr) [n:127.0.0.1:42951_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/acollectionafterbaddelete/state.json] for collection [acollectionafterbaddelete] has occurred - updating... (live nodes size: [4])
[junit4] 2> 1296641 INFO (zkCallback-1451-thread-1-processing-n:127.0.0.1:41577_solr) [n:127.0.0.1:41577_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/acollectionafterbaddelete/state.json] for collection [acollectionafterbaddelete] has occurred - updating... (live nodes size: [4])
[junit4] 2> 1296641 INFO (zkCallback-1454-thread-1-processing-n:127.0.0.1:42951_solr) [n:127.0.0.1:42951_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/acollectionafterbaddelete/state.json] for collection [acollectionafterbaddelete] has occurred - updating... (live nodes size: [4])
[junit4] 2> 1296642 INFO (zkCallback-1451-thread-2-processing-n:127.0.0.1:41577_solr) [n:127.0.0.1:41577_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/acollectionafterbaddelete/state.json] for collection [acollectionafterbaddelete] has occurred - updating... (live nodes size: [4])
[junit4] 2> 1296691 INFO (qtp22071740-11724) [n:127.0.0.1:42951_solr c:acollectionafterbaddelete s:shard1 r:core_node1 x:acollectionafterbaddelete_shard1_replica_n1] o.a.s.c.ZkController I am the leader, no recovery necessary
[junit4] 2> 1296692 INFO (qtp22071740-11724) [n:127.0.0.1:42951_solr c:acollectionafterbaddelete s:shard1 r:core_node1 x:acollectionafterbaddelete_shard1_replica_n1] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={qt=/admin/cores&coreNodeName=core_node1&collection.configName=conf&newCollection=true&name=acollectionafterbaddelete_shard1_replica_n1&action=CREATE&numShards=1&collection=acollectionafterbaddelete&shard=shard1&wt=javabin&version=2&replicaType=NRT} status=0 QTime=1722
[junit4] 2> 1296793 INFO (zkCallback-1451-thread-1-processing-n:127.0.0.1:41577_solr) [n:127.0.0.1:41577_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/acollectionafterbaddelete/state.json] for collection [acollectionafterbaddelete] has occurred - updating... (live nodes size: [4])
[junit4] 2> 1296793 INFO (zkCallback-1454-thread-1-processing-n:127.0.0.1:42951_solr) [n:127.0.0.1:42951_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/acollectionafterbaddelete/state.json] for collection [acollectionafterbaddelete] has occurred - updating... (live nodes size: [4])
[junit4] 2> 1296793 INFO (zkCallback-1454-thread-2-processing-n:127.0.0.1:42951_solr) [n:127.0.0.1:42951_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/acollectionafterbaddelete/state.json] for collection [acollectionafterbaddelete] has occurred - updating... (live nodes size: [4])
[junit4] 2> 1296793 INFO (zkCallback-1451-thread-2-processing-n:127.0.0.1:41577_solr) [n:127.0.0.1:41577_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/acollectionafterbaddelete/state.json] for collection [acollectionafterbaddelete] has occurred - updating... (live nodes size: [4])
[junit4] 2> 1297042 INFO (qtp26363452-11735) [n:127.0.0.1:41577_solr c:acollectionafterbaddelete s:shard1 r:core_node2 x:acollectionafterbaddelete_shard1_replica_n2] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={qt=/admin/cores&coreNodeName=core_node2&collection.configName=conf&newCollection=true&name=acollectionafterbaddelete_shard1_replica_n2&action=CREATE&numShards=1&collection=acollectionafterbaddelete&shard=shard1&wt=javabin&version=2&replicaType=NRT} status=0 QTime=2072
[junit4] 2> 1297043 INFO (qtp22071740-11746) [n:127.0.0.1:42951_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> 1297143 INFO (zkCallback-1451-thread-2-processing-n:127.0.0.1:41577_solr) [n:127.0.0.1:41577_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/acollectionafterbaddelete/state.json] for collection [acollectionafterbaddelete] has occurred - updating... (live nodes size: [4])
[junit4] 2> 1297143 INFO (zkCallback-1454-thread-1-processing-n:127.0.0.1:42951_solr) [n:127.0.0.1:42951_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/acollectionafterbaddelete/state.json] for collection [acollectionafterbaddelete] has occurred - updating... (live nodes size: [4])
[junit4] 2> 1297143 INFO (zkCallback-1454-thread-2-processing-n:127.0.0.1:42951_solr) [n:127.0.0.1:42951_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/acollectionafterbaddelete/state.json] for collection [acollectionafterbaddelete] has occurred - updating... (live nodes size: [4])
[junit4] 2> 1297143 INFO (zkCallback-1451-thread-1-processing-n:127.0.0.1:41577_solr) [n:127.0.0.1:41577_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/acollectionafterbaddelete/state.json] for collection [acollectionafterbaddelete] has occurred - updating... (live nodes size: [4])
[junit4] 2> 1298043 INFO (qtp22071740-11746) [n:127.0.0.1:42951_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={replicationFactor=2&collection.configName=conf&name=acollectionafterbaddelete&nrtReplicas=2&action=CREATE&numShards=1&wt=javabin&version=2} status=0 QTime=3378
[junit4] 2> 1298044 INFO (TEST-CollectionsAPIDistributedZkTest.testDeleteNonExistentCollection-seed#[22F645446B8A6553]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testDeleteNonExistentCollection
[junit4] 2> 1298070 INFO (TEST-CollectionsAPIDistributedZkTest.testMissingNumShards-seed#[22F645446B8A6553]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testMissingNumShards
[junit4] 2> 1298070 INFO (TEST-CollectionsAPIDistributedZkTest.testMissingNumShards-seed#[22F645446B8A6553]) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (4)
[junit4] 2> 1298071 INFO (qtp22071740-11751) [n:127.0.0.1:42951_solr ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :delete with params name=acollectionafterbaddelete&action=DELETE&wt=javabin&version=2 and sendToOCPQueue=true
[junit4] 2> 1298072 INFO (OverseerCollectionConfigSetProcessor-98755367785594891-127.0.0.1:43357_solr-n_0000000000) [n:127.0.0.1:43357_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> 1298072 INFO (OverseerThreadFactory-4007-thread-3-processing-n:127.0.0.1:43357_solr) [n:127.0.0.1:43357_solr ] o.a.s.c.OverseerCollectionMessageHandler Executing Collection Cmd : action=UNLOAD&deleteInstanceDir=true&deleteDataDir=true
[junit4] 2> 1298073 INFO (qtp26363452-11740) [n:127.0.0.1:41577_solr ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.core.acollectionafterbaddelete.shard1.replica_n2, tag=null
[junit4] 2> 1298073 INFO (qtp26363452-11740) [n:127.0.0.1:41577_solr ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@3033c1: rootName = null, domain = solr.core.acollectionafterbaddelete.shard1.replica_n2, service url = null, agent id = null] for registry solr.core.acollectionafterbaddelete.shard1.replica_n2 / com.codahale.metrics.MetricRegistry@1709cb7
[junit4] 2> 1298074 INFO (qtp22071740-11743) [n:127.0.0.1:42951_solr ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.core.acollectionafterbaddelete.shard1.replica_n1, tag=null
[junit4] 2> 1298075 INFO (qtp22071740-11743) [n:127.0.0.1:42951_solr ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@982c17: rootName = null, domain = solr.core.acollectionafterbaddelete.shard1.replica_n1, service url = null, agent id = null] for registry solr.core.acollectionafterbaddelete.shard1.replica_n1 / com.codahale.metrics.MetricRegistry@142b6ea
[junit4] 2> 1298083 INFO (qtp22071740-11743) [n:127.0.0.1:42951_solr ] o.a.s.c.SolrCore [acollectionafterbaddelete_shard1_replica_n1] CLOSING SolrCore org.apache.solr.core.SolrCore@fe1856
[junit4] 2> 1298083 INFO (qtp22071740-11743) [n:127.0.0.1:42951_solr ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.core.acollectionafterbaddelete.shard1.replica_n1, tag=16652374
[junit4] 2> 1298083 INFO (qtp22071740-11743) [n:127.0.0.1:42951_solr ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.collection.acollectionafterbaddelete.shard1.leader, tag=16652374
[junit4] 2> 1298084 WARN (zkCallback-1451-thread-1-processing-n:127.0.0.1:41577_solr) [n:127.0.0.1:41577_solr ] o.a.s.c.LeaderElector
[junit4] 2> org.apache.solr.common.SolrException: SolrCore not found:acollectionafterbaddelete_shard1_replica_n2 in []
[junit4] 2> at org.apache.solr.cloud.ShardLeaderElectionContext.runLeaderProcess(ElectionContext.java:297)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.runIamLeaderProcess(LeaderElector.java:170)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:135)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.access$200(LeaderElector.java:56)
[junit4] 2> at org.apache.solr.cloud.LeaderElector$ElectionWatcher.process(LeaderElector.java:348)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$3.lambda$process$0(SolrZkClient.java:269)
[junit4] 2> at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
[junit4] 2> at java.util.concurrent.FutureTask.run(FutureTask.java:266)
[junit4] 2> at org.apache.solr.common.util.ExecutorUtil$MDCAwareThreadPoolExecutor.lambda$execute$0(ExecutorUtil.java:188)
[junit4] 2> at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
[junit4] 2> at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
[junit4] 2> at java.lang.Thread.run(Thread.java:748)
[junit4] 2> 1298086 INFO (qtp22071740-11743) [n:127.0.0.1:42951_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={deleteInstanceDir=true&core=acollectionafterbaddelete_shard1_replica_n1&qt=/admin/cores&deleteDataDir=true&action=UNLOAD&wt=javabin&version=2} status=0 QTime=11
[junit4] 2> 1298088 INFO (qtp26363452-11740) [n:127.0.0.1:41577_solr ] o.a.s.c.SolrCore [acollectionafterbaddelete_shard1_replica_n2] CLOSING SolrCore org.apache.solr.core.SolrCore@f2df88
[junit4] 2> 1298088 INFO (qtp26363452-11740) [n:127.0.0.1:41577_solr ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.core.acollectionafterbaddelete.shard1.replica_n2, tag=15916936
[junit4] 2> 1298088 INFO (qtp26363452-11740) [n:127.0.0.1:41577_solr ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.collection.acollectionafterbaddelete.shard1.leader, tag=15916936
[junit4] 2> 1298089 INFO (qtp26363452-11740) [n:127.0.0.1:41577_solr ] o.a.s.c.ShardLeaderElectionContextBase No version found for ephemeral leader parent node, won't remove previous leader registration.
[junit4] 2> 1298089 INFO (qtp26363452-11740) [n:127.0.0.1:41577_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={deleteInstanceDir=true&core=acollectionafterbaddelete_shard1_replica_n2&qt=/admin/cores&deleteDataDir=true&action=UNLOAD&wt=javabin&version=2} status=0 QTime=16
[junit4] 2> 1298792 INFO (qtp22071740-11751) [n:127.0.0.1:42951_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={name=acollectionafterbaddelete&action=DELETE&wt=javabin&version=2} status=0 QTime=720
[junit4] 2> 1298793 INFO (qtp22071740-11720) [n:127.0.0.1:42951_solr ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :create with params replicationFactor=10&collection.configName=conf&name=acollection&action=CREATE&wt=javabin&version=2 and sendToOCPQueue=true
[junit4] 2> 1298793 INFO (OverseerThreadFactory-4007-thread-4-processing-n:127.0.0.1:43357_solr) [n:127.0.0.1:43357_solr ] o.a.s.c.CreateCollectionCmd Create collection acollection
[junit4] 2> 1298794 INFO (OverseerCollectionConfigSetProcessor-98755367785594891-127.0.0.1:43357_solr-n_0000000000) [n:127.0.0.1:43357_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> 1298794 ERROR (OverseerThreadFactory-4007-thread-4-processing-n:127.0.0.1:43357_solr) [n:127.0.0.1:43357_solr ] o.a.s.c.OverseerCollectionMessageHandler Collection: acollection operation: create failed:org.apache.solr.common.SolrException: numShards is a required param (when using CompositeId router).
[junit4] 2> at org.apache.solr.cloud.CreateCollectionCmd.call(CreateCollectionCmd.java:117)
[junit4] 2> at org.apache.solr.cloud.OverseerCollectionMessageHandler.processMessage(OverseerCollectionMessageHandler.java:227)
[junit4] 2> at org.apache.solr.cloud.OverseerTaskProcessor$Runner.run(OverseerTaskProcessor.java:464)
[junit4] 2> at org.apache.solr.common.util.ExecutorUtil$MDCAwareThreadPoolExecutor.lambda$execute$0(ExecutorUtil.java:188)
[junit4] 2> at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
[junit4] 2> at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
[junit4] 2> at java.lang.Thread.run(Thread.java:748)
[junit4] 2>
[junit4] 2> 1298795 INFO (qtp22071740-11720) [n:127.0.0.1:42951_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={replicationFactor=10&collection.configName=conf&name=acollection&action=CREATE&wt=javabin&version=2} status=400 QTime=2
[junit4] 2> 1298795 INFO (TEST-CollectionsAPIDistributedZkTest.testMissingNumShards-seed#[22F645446B8A6553]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testMissingNumShards
[junit4] 2> 1298826 INFO (TEST-CollectionsAPIDistributedZkTest.testTooManyReplicas-seed#[22F645446B8A6553]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testTooManyReplicas
[junit4] 2> 1298827 INFO (TEST-CollectionsAPIDistributedZkTest.testTooManyReplicas-seed#[22F645446B8A6553]) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (4)
[junit4] 2> 1298828 INFO (qtp22071740-11746) [n:127.0.0.1:42951_solr ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :create with params replicationFactor=10&collection.configName=conf&name=collection&nrtReplicas=10&action=CREATE&numShards=2&wt=javabin&version=2 and sendToOCPQueue=true
[junit4] 2> 1298829 INFO (OverseerThreadFactory-4007-thread-5-processing-n:127.0.0.1:43357_solr) [n:127.0.0.1:43357_solr ] o.a.s.c.CreateCollectionCmd Create collection collection
[junit4] 2> 1298829 INFO (OverseerCollectionConfigSetProcessor-98755367785594891-127.0.0.1:43357_solr-n_0000000000) [n:127.0.0.1:43357_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> 1298829 WARN (OverseerThreadFactory-4007-thread-5-processing-n:127.0.0.1:43357_solr) [n:127.0.0.1:43357_solr ] o.a.s.c.CreateCollectionCmd Specified number of replicas of 10 on collection collection is higher than the number of Solr instances currently live or live and part of your createNodeSet(4). It's unusual to run two replica of the same slice on the same Solr-instance.
[junit4] 2> 1298829 ERROR (OverseerThreadFactory-4007-thread-5-processing-n:127.0.0.1:43357_solr) [n:127.0.0.1:43357_solr ] o.a.s.c.OverseerCollectionMessageHandler Collection: collection operation: create failed:org.apache.solr.common.SolrException: Cannot create collection collection. Value of maxShardsPerNode is 1, and the number of nodes currently live or live and part of your createNodeSet is 4. This allows a maximum of 4 to be created. Value of numShards is 2, value of nrtReplicas is 10, value of tlogReplicas is 0 and value of pullReplicas is 0. This requires 20 shards to be created (higher than the allowed number)
[junit4] 2> at org.apache.solr.cloud.CreateCollectionCmd.call(CreateCollectionCmd.java:164)
[junit4] 2> at org.apache.solr.cloud.OverseerCollectionMessageHandler.processMessage(OverseerCollectionMessageHandler.java:227)
[junit4] 2> at org.apache.solr.cloud.OverseerTaskProcessor$Runner.run(OverseerTaskProcessor.java:464)
[junit4] 2> at org.apache.solr.common.util.ExecutorUtil$MDCAwareThreadPoolExecutor.lambda$execute$0(ExecutorUtil.java:188)
[junit4] 2> at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
[junit4] 2> at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
[junit4] 2> at java.lang.Thread.run(Thread.java:748)
[junit4] 2>
[junit4] 2> 1298830 INFO (qtp22071740-11746) [n:127.0.0.1:42951_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={replicationFactor=10&collection.configName=conf&name=collection&nrtReplicas=10&action=CREATE&numShards=2&wt=javabin&version=2} status=400 QTime=2
[junit4] 2> 1298831 INFO (TEST-CollectionsAPIDistributedZkTest.testTooManyReplicas-seed#[22F645446B8A6553]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testTooManyReplicas
[junit4] 2> 1298860 INFO (TEST-CollectionsAPIDistributedZkTest.testMaxNodesPerShard-seed#[22F645446B8A6553]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testMaxNodesPerShard
[junit4] 2> 1298861 INFO (TEST-CollectionsAPIDistributedZkTest.testMaxNodesPerShard-seed#[22F645446B8A6553]) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (4)
[junit4] 2> 1298863 INFO (qtp22071740-11743) [n:127.0.0.1:42951_solr ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :create with params replicationFactor=2&collection.configName=conf&name=oversharded&nrtReplicas=2&action=CREATE&numShards=3&wt=javabin&version=2 and sendToOCPQueue=true
[junit4] 2> 1298867 INFO (OverseerThreadFactory-4007-thread-5-processing-n:127.0.0.1:43357_solr) [n:127.0.0.1:43357_solr ] o.a.s.c.CreateCollectionCmd Create collection oversharded
[junit4] 2> 1298868 INFO (OverseerCollectionConfigSetProcessor-98755367785594891-127.0.0.1:43357_solr-n_0000000000) [n:127.0.0.1:43357_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> 1298868 ERROR (OverseerThreadFactory-4007-thread-5-processing-n:127.0.0.1:43357_solr) [n:127.0.0.1:43357_solr ] o.a.s.c.OverseerCollectionMessageHandler Collection: oversharded operation: create failed:org.apache.solr.common.SolrException: Cannot create collection oversharded. Value of maxShardsPerNode is 1, and the number of nodes currently live or live and part of your createNodeSet is 4. This allows a maximum of 4 to be created. Value of numShards is 3, value of nrtReplicas is 2, value of tlogReplicas is 0 and value of pullReplicas is 0. This requires 6 shards to be created (higher than the allowed number)
[junit4] 2> at org.apache.solr.cloud.CreateCollectionCmd.call(CreateCollectionCmd.java:164)
[junit4] 2> at org.apache.solr.cloud.OverseerCollectionMessageHandler.processMessage(OverseerCollectionMessageHandler.java:227)
[junit4] 2> at org.apache.solr.cloud.OverseerTaskProcessor$Runner.run(OverseerTaskProcessor.java:464)
[junit4] 2> at org.apache.solr.common.util.ExecutorUtil$MDCAwareThreadPoolExecutor.lambda$execute$0(ExecutorUtil.java:188)
[junit4] 2> at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
[junit4] 2> at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
[junit4] 2> at java.lang.Thread.run(Thread.java:748)
[junit4] 2>
[junit4] 2> 1298869 INFO (qtp22071740-11743) [n:127.0.0.1:42951_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={replicationFactor=2&collection.configName=conf&name=oversharded&nrtReplicas=2&action=CREATE&numShards=3&wt=javabin&version=2} status=400 QTime=5
[junit4] 2> 1298869 INFO (TEST-CollectionsAPIDistributedZkTest.testMaxNodesPerShard-seed#[22F645446B8A6553]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testMaxNodesPerShard
[junit4] 2> 1298901 INFO (TEST-CollectionsAPIDistributedZkTest.addReplicaTest-seed#[22F645446B8A6553]) [ ] o.a.s.SolrTestCaseJ4 ###Starting addReplicaTest
[junit4] 2> 1298902 INFO (TEST-CollectionsAPIDistributedZkTest.addReplicaTest-seed#[22F645446B8A6553]) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (4)
[junit4] 2> 1298903 INFO (qtp22071740-11751) [n:127.0.0.1:42951_solr ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :create with params replicationFactor=2&collection.configName=conf&maxShardsPerNode=4&name=addReplicaColl&nrtReplicas=2&action=CREATE&numShards=2&wt=javabin&version=2 and sendToOCPQueue=true
[junit4] 2> 1298904 INFO (OverseerThreadFactory-4007-thread-5-processing-n:127.0.0.1:43357_solr) [n:127.0.0.1:43357_solr ] o.a.s.c.CreateCollectionCmd Create collection addReplicaColl
[junit4] 2> 1298904 INFO (OverseerCollectionConfigSetProcessor-98755367785594891-127.0.0.1:43357_solr-n_0000000000) [n:127.0.0.1:43357_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> 1299108 INFO (OverseerStateUpdate-98755367785594891-127.0.0.1:43357_solr-n_0000000000) [n:127.0.0.1:43357_solr ] o.a.s.c.o.SliceMutator createReplica() {
[junit4] 2> "operation":"ADDREPLICA",
[junit4] 2> "collection":"addReplicaColl",
[junit4] 2> "shard":"shard1",
[junit4] 2> "core":"addReplicaColl_shard1_replica_n1",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"http://127.0.0.1:43357/solr",
[junit4] 2> "type":"NRT"}
[junit4] 2> 1299108 INFO (OverseerStateUpdate-98755367785594891-127.0.0.1:43357_solr-n_0000000000) [n:127.0.0.1:43357_solr ] o.a.s.c.o.SliceMutator createReplica() {
[junit4] 2> "operation":"ADDREPLICA",
[junit4] 2> "collection":"addReplicaColl",
[junit4] 2> "shard":"shard1",
[junit4] 2> "core":"addReplicaColl_shard1_replica_n2",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"http://127.0.0.1:40241/solr",
[junit4] 2> "type":"NRT"}
[junit4] 2> 1299109 INFO (OverseerStateUpdate-98755367785594891-127.0.0.1:43357_solr-n_0000000000) [n:127.0.0.1:43357_solr ] o.a.s.c.o.SliceMutator createReplica() {
[junit4] 2> "operation":"ADDREPLICA",
[junit4] 2> "collection":"addReplicaColl",
[junit4] 2> "shard":"shard2",
[junit4] 2> "core":"addReplicaColl_shard2_replica_n1",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"http://127.0.0.1:41577/solr",
[junit4] 2> "type":"NRT"}
[junit4] 2> 1299109 INFO (OverseerStateUpdate-98755367785594891-127.0.0.1:43357_solr-n_0000000000) [n:127.0.0.1:43357_solr ] o.a.s.c.o.SliceMutator createReplica() {
[junit4] 2> "operation":"ADDREPLICA",
[junit4] 2> "collection":"addReplicaColl",
[junit4] 2> "shard":"shard2",
[junit4] 2> "core":"addReplicaColl_shard2_replica_n2",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"http://127.0.0.1:42951/solr",
[junit4] 2> "type":"NRT"}
[junit4] 2> 1299311 INFO (qtp10275674-11742) [n:127.0.0.1:43357_solr ] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&coreNodeName=core_node1&collection.configName=conf&newCollection=true&name=addReplicaColl_shard1_replica_n1&action=CREATE&numShards=2&collection=addReplicaColl&shard=shard1&wt=javabin&version=2&replicaType=NRT
[junit4] 2> 1299311 INFO (qtp16839552-11744) [n:127.0.0.1:40241_solr ] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&coreNodeName=core_node2&collection.configName=conf&newCollection=true&name=addReplicaColl_shard1_replica_n2&action=CREATE&numShards=2&collection=addReplicaColl&shard=shard1&wt=javabin&version=2&replicaType=NRT
[junit4] 2> 1299311 INFO (qtp10275674-11742) [n:127.0.0.1:43357_solr ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores
[junit4] 2> 1299311 INFO (qtp16839552-11744) [n:127.0.0.1:40241_solr ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores
[junit4] 2> 1299311 INFO (qtp26363452-11722) [n:127.0.0.1:41577_solr ] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&coreNodeName=core_node3&collection.configName=conf&newCollection=true&name=addReplicaColl_shard2_replica_n1&action=CREATE&numShards=2&collection=addReplicaColl&shard=shard2&wt=javabin&version=2&replicaType=NRT
[junit4] 2> 1299312 INFO (qtp22071740-11724) [n:127.0.0.1:42951_solr ] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&coreNodeName=core_node4&collection.configName=conf&newCollection=true&name=addReplicaColl_shard2_replica_n2&action=CREATE&numShards=2&collection=addReplicaColl&shard=shard2&wt=javabin&version=2&replicaType=NRT
[junit4] 2> 1299415 INFO (zkCallback-1454-thread-1-processing-n:127.0.0.1:42951_solr) [n:127.0.0.1:42951_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/addReplicaColl/state.json] for collection [addReplicaColl] has occurred - updating... (live nodes size: [4])
[junit4] 2> 1299415 INFO (zkCallback-1452-thread-1-processing-n:127.0.0.1:40241_solr) [n:127.0.0.1:40241_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/addReplicaColl/state.json] for collection [addReplicaColl] has occurred - updating... (live nodes size: [4])
[junit4] 2> 1299415 INFO (zkCallback-1452-thread-2-processing-n:127.0.0.1:40241_solr) [n:127.0.0.1:40241_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/addReplicaColl/state.json] for collection [addReplicaColl] has occurred - updating... (live nodes size: [4])
[junit4] 2> 1299415 INFO (zkCallback-1451-thread-1-processing-n:127.0.0.1:41577_solr) [n:127.0.0.1:41577_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/addReplicaColl/state.json] for collection [addReplicaColl] has occurred - updating... (live nodes size: [4])
[junit4] 2> 1299415 INFO (zkCallback-1451-thread-2-processing-n:127.0.0.1:41577_solr) [n:127.0.0.1:41577_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/addReplicaColl/state.json] for collection [addReplicaColl] has occurred - updating... (live nodes size: [4])
[junit4] 2> 1299415 INFO (zkCallback-1454-thread-2-processing-n:127.0.0.1:42951_solr) [n:127.0.0.1:42951_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/addReplicaColl/state.json] for collection [addReplicaColl] has occurred - updating... (live nodes size: [4])
[junit4] 2> 1299415 INFO (zkCallback-1453-thread-2-processing-n:127.0.0.1:43357_solr) [n:127.0.0.1:43357_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/addReplicaColl/state.json] for collection [addReplicaColl] has occurred - updating... (live nodes size: [4])
[junit4] 2> 1299415 INFO (zkCallback-1453-thread-1-processing-n:127.0.0.1:43357_solr) [n:127.0.0.1:43357_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/addReplicaColl/state.json] for collection [addReplicaColl] has occurred - updating... (live nodes size: [4])
[junit4] 2> 1300321 INFO (qtp26363452-11722) [n:127.0.0.1:41577_solr c:addReplicaColl s:shard2 r:core_node3 x:addReplicaColl_shard2_replica_n1] o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.0.1
[junit4] 2> 1300321 INFO (qtp16839552-11744) [n:127.0.0.1:40241_solr c:addReplicaColl s:shard1 r:core_node2 x:addReplicaColl_shard1_replica_n2] o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.0.1
[junit4] 2> 1300321 INFO (qtp10275674-11742) [n:127.0.0.1:43357_solr c:addReplicaColl s:shard1 r:core_node1 x:addReplicaColl_shard1_replica_n1] o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.0.1
[junit4] 2> 1300321 INFO (qtp22071740-11724) [n:127.0.0.1:42951_solr c:addReplicaColl s:shard2 r:core_node4 x:addReplicaColl_shard2_replica_n2] o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.0.1
[junit4] 2> 1300341 INFO (qtp22071740-11724) [n:127.0.0.1:42951_solr c:addReplicaColl s:shard2 r:core_node4 x:addReplicaColl_shard2_replica_n2] o.a.s.s.IndexSchema [addReplicaColl_shard2_replica_n2] Schema name=minimal
[junit4] 2> 1300341 INFO (qtp16839552-11744) [n:127.0.0.1:40241_solr c:addReplicaColl s:shard1 r:core_node2 x:addReplicaColl_shard1_replica_n2] o.a.s.s.IndexSchema [addReplicaColl_shard1_replica_n2] Schema name=minimal
[junit4] 2> 1300342 INFO (qtp26363452-11722) [n:127.0.0.1:41577_solr c:addReplicaColl s:shard2 r:core_node3 x:addReplicaColl_shard2_replica_n1] o.a.s.s.IndexSchema [addReplicaColl_shard2_replica_n1] Schema name=minimal
[junit4] 2> 1300343 INFO (qtp22071740-11724) [n:127.0.0.1:42951_solr c:addReplicaColl s:shard2 r:core_node4 x:addReplicaColl_shard2_replica_n2] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
[junit4] 2> 1300343 INFO (qtp22071740-11724) [n:127.0.0.1:42951_solr c:addReplicaColl s:shard2 r:core_node4 x:addReplicaColl_shard2_replica_n2] o.a.s.c.CoreContainer Creating SolrCore 'addReplicaColl_shard2_replica_n2' using configuration from collection addReplicaColl, trusted=true
[junit4] 2> 1300343 INFO (qtp16839552-11744) [n:127.0.0.1:40241_solr c:addReplicaColl s:shard1 r:core_node2 x:addReplicaColl_shard1_replica_n2] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
[junit4] 2> 1300343 INFO (qtp16839552-11744) [n:127.0.0.1:40241_solr c:addReplicaColl s:shard1 r:core_node2 x:addReplicaColl_shard1_replica_n2] o.a.s.c.CoreContainer Creating SolrCore 'addReplicaColl_shard1_replica_n2' using configuration from collection addReplicaColl, trusted=true
[junit4] 2> 1300343 INFO (qtp26363452-11722) [n:127.0.0.1:41577_solr c:addReplicaColl s:shard2 r:core_node3 x:addReplicaColl_shard2_replica_n1] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
[junit4] 2> 1300343 INFO (qtp10275674-11742) [n:127.0.0.1:43357_solr c:addReplicaColl s:shard1 r:core_node1 x:addReplicaColl_shard1_replica_n1] o.a.s.s.IndexSchema [addReplicaColl_shard1_replica_n1] Schema name=minimal
[junit4] 2> 1300343 INFO (qtp26363452-11722) [n:127.0.0.1:41577_solr c:addReplicaColl s:shard2 r:core_node3 x:addReplicaColl_shard2_replica_n1] o.a.s.c.CoreContainer Creating SolrCore 'addReplicaColl_shard2_replica_n1' using configuration from collection addReplicaColl, trusted=true
[junit4] 2> 1300344 INFO (qtp26363452-11722) [n:127.0.0.1:41577_solr c:addReplicaColl s:shard2 r:core_node3 x:addReplicaColl_shard2_replica_n1] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.core.addReplicaColl.shard2.replica_n1' (registry 'solr.core.addReplicaColl.shard2.replica_n1') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@197c0cb
[junit4] 2> 1300344 INFO (qtp16839552-11744) [n:127.0.0.1:40241_solr c:addReplicaColl s:shard1 r:core_node2 x:addReplicaColl_shard1_replica_n2] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.core.addReplicaColl.shard1.replica_n2' (registry 'solr.core.addReplicaColl.shard1.replica_n2') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@197c0cb
[junit4] 2> 1300344 INFO (qtp26363452-11722) [n:127.0.0.1:41577_solr c:addReplicaColl s:shard2 r:core_node3 x:addReplicaColl_shard2_replica_n1] o.a.s.c.SolrCore solr.RecoveryStrategy.Builder
[junit4] 2> 1300344 INFO (qtp22071740-11724) [n:127.0.0.1:42951_solr c:addReplicaColl s:shard2 r:core_node4 x:addReplicaColl_shard2_replica_n2] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.core.addReplicaColl.shard2.replica_n2' (registry 'solr.core.addReplicaColl.shard2.replica_n2') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@197c0cb
[junit4] 2> 1300344 INFO (qtp16839552-11744) [n:127.0.0.1:40241_solr c:addReplicaColl s:shard1 r:core_node2 x:addReplicaColl_shard1_replica_n2] o.a.s.c.SolrCore solr.RecoveryStrategy.Builder
[junit4] 2> 1300344 INFO (qtp26363452-11722) [n:127.0.0.1:41577_solr c:addReplicaColl s:shard2 r:core_node3 x:addReplicaColl_shard2_replica_n1] o.a.s.c.SolrCore [[addReplicaColl_shard2_replica_n1] ] Opening new SolrCore at [/home/jenkins/workspace/Lucene-Solr-7.0-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.CollectionsAPIDistributedZkTest_22F645446B8A6553-001/tempDir-001/node4/addReplicaColl_shard2_replica_n1], dataDir=[/home/jenkins/workspace/Lucene-Solr-7.0-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.CollectionsAPIDistributedZkTest_22F645446B8A6553-001/tempDir-001/node4/addReplicaColl_shard2_replica_n1/data/]
[junit4] 2> 1300344 INFO (qtp22071740-11724) [n:127.0.0.1:42951_solr c:addReplicaColl s:shard2 r:core_node4 x:addReplicaColl_shard2_replica_n2] o.a.s.c.SolrCore solr.RecoveryStrategy.Builder
[junit4] 2> 1300344 INFO (qtp16839552-11744) [n:127.0.0.1:40241_solr c:addReplicaColl s:shard1 r:core_node2 x:addReplicaColl_shard1_replica_n2] o.a.s.c.SolrCore [[addReplicaColl_shard1_replica_n2] ] Opening new SolrCore at [/home/jenkins/workspace/Lucene-Solr-7.0-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.CollectionsAPIDistributedZkTest_22F645446B8A6553-001/tempDir-001/node2/addReplicaColl_shard1_replica_n2], dataDir=[/home/jenkins/workspace/Lucene-Solr-7.0-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.CollectionsAPIDistributedZkTest_22F645446B8A6553-001/tempDir-001/node2/addReplicaColl_shard1_replica_n2/data/]
[junit4] 2> 1300344 INFO (qtp22071740-11724) [n:127.0.0.1:42951_solr c:addReplicaColl s:shard2 r:core_node4 x:addReplicaColl_shard2_replica_n2] o.a.s.c.SolrCore [[addReplicaColl_shard2_replica_n2] ] Opening new SolrCore at [/home/jenkins/workspace/Lucene-Solr-7.0-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.CollectionsAPIDistributedZkTest_22F645446B8A6553-001/tempDir-001/node1/addReplicaColl_shard2_replica_n2], dataDir=[/home/jenkins/workspace/Lucene-Solr-7.0-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.CollectionsAPIDistributedZkTest_22F645446B8A6553-001/tempDir-001/node1/addReplicaColl_shard2_replica_n2/data/]
[junit4] 2> 1300345 INFO (qtp10275674-11742) [n:127.0.0.1:43357_solr c:addReplicaColl s:shard1 r:core_node1 x:addReplicaColl_shard1_replica_n1] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
[junit4] 2> 1300345 INFO (qtp10275674-11742) [n:127.0.0.1:43357_solr c:addReplicaColl s:shard1 r:core_node1 x:addReplicaColl_shard1_replica_n1] o.a.s.c.CoreContainer Creating SolrCore 'addReplicaColl_shard1_replica_n1' using configuration from collection addReplicaColl, trusted=true
[junit4] 2> 1300346 INFO (qtp10275674-11742) [n:127.0.0.1:43357_solr c:addReplicaColl s:shard1 r:core_node1 x:addReplicaColl_shard1_replica_n1] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.core.addReplicaColl.shard1.replica_n1' (registry 'solr.core.addReplicaColl.shard1.replica_n1') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@197c0cb
[junit4] 2> 1300346 INFO (qtp10275674-11742) [n:127.0.0.1:43357_solr c:addReplicaColl s:shard1 r:core_node1 x:addReplicaColl_shard1_replica_n1] o.a.s.c.SolrCore solr.RecoveryStrategy.Builder
[junit4] 2> 1300346 INFO (qtp10275674-11742) [n:127.0.0.1:43357_solr c:addReplicaColl s:shard1 r:core_node1 x:addReplicaColl_shard1_replica_n1] o.a.s.c.SolrCore [[addReplicaColl_shard1_replica_n1] ] Opening new SolrCore at [/home/jenkins/workspace/Lucene-Solr-7.0-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.CollectionsAPIDistributedZkTest_22F645446B8A6553-001/tempDir-001/node3/addReplicaColl_shard1_replica_n1], dataDir=[/home/jenkins/workspace/Lucene-Solr-7.0-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.CollectionsAPIDistributedZkTest_22F645446B8A6553-001/tempDir-001/node3/addReplicaColl_shard1_replica_n1/data/]
[junit4] 2> 1300383 INFO (qtp26363452-11722) [n:127.0.0.1:41577_solr c:addReplicaColl s:shard2 r:core_node3 x:addReplicaColl_shard2_replica_n1] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
[junit4] 2> 1300383 INFO (qtp26363452-11722) [n:127.0.0.1:41577_solr c:addReplicaColl s:shard2 r:core_node3 x:addReplicaColl_shard2_replica_n1] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 1300384 INFO (qtp26363452-11722) [n:127.0.0.1:41577_solr c:addReplicaColl s:shard2 r:core_node3 x:addReplicaColl_shard2_replica_n1] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 1300384 INFO (qtp26363452-11722) [n:127.0.0.1:41577_solr c:addReplicaColl s:shard2 r:core_node3 x:addReplicaColl_shard2_replica_n1] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 1300386 INFO (qtp26363452-11722) [n:127.0.0.1:41577_solr c:addReplicaColl s:shard2 r:core_node3 x:addReplicaColl_shard2_replica_n1] o.a.s.s.SolrIndexSearcher Opening [Searcher@5552c4[addReplicaColl_shard2_replica_n1] main]
[junit4] 2> 1300386 INFO (qtp26363452-11722) [n:127.0.0.1:41577_solr c:addReplicaColl s:shard2 r:core_node3 x:addReplicaColl_shard2_replica_n1] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf
[junit4] 2> 1300403 INFO (qtp26363452-11722) [n:127.0.0.1:41577_solr c:addReplicaColl s:shard2 r:core_node3 x:addReplicaColl_shard2_replica_n1] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf
[junit4] 2> 1300404 INFO (qtp26363452-11722) [n:127.0.0.1:41577_solr c:addReplicaColl s:shard2 r:core_node3 x:addReplicaColl_shard2_replica_n1] o.a.s.h.ReplicationHandler Commits will be reserved for 10000
[junit4] 2> 1300404 INFO (qtp26363452-11722) [n:127.0.0.1:41577_solr c:addReplicaColl s:shard2 r:core_node3 x:addReplicaColl_shard2_replica_n1] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1580085891027697664
[junit4] 2> 1300406 INFO (searcherExecutor-4028-thread-1-processing-n:127.0.0.1:41577_solr x:addReplicaColl_shard2_replica_n1 s:shard2 c:addReplicaColl r:core_node3) [n:127.0.0.1:41577_solr c:addReplicaColl s:shard2 r:core_node3 x:addReplicaColl_shard2_replica_n1] o.a.s.c.SolrCore [addReplicaColl_shard2_replica_n1] Registered new searcher Searcher@5552c4[addReplicaColl_shard2_replica_n1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 1300406 INFO (qtp10275674-11742) [n:127.0.0.1:43357_solr c:addReplicaColl s:shard1 r:core_node1 x:addReplicaColl_shard1_replica_n1] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
[junit4] 2> 1300406 INFO (qtp10275674-11742) [n:127.0.0.1:43357_solr c:addReplicaColl s:shard1 r:core_node1 x:addReplicaColl_shard1_replica_n1] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 1300407 INFO (qtp10275674-11742) [n:127.0.0.1:43357_solr c:addReplicaColl s:shard1 r:core_node1 x:addReplicaColl_shard1_replica_n1] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 1300407 INFO (qtp10275674-11742) [n:127.0.0.1:43357_solr c:addReplicaColl s:shard1 r:core_node1 x:addReplicaColl_shard1_replica_n1] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 1300408 INFO (qtp26363452-11722) [n:127.0.0.1:41577_solr c:addReplicaColl s:shard2 r:core_node3 x:addReplicaColl_shard2_replica_n1] o.a.s.c.ShardLeaderElectionContext Waiting until we see more replicas up for shard shard2: total=2 found=1 timeoutin=9999ms
[junit4] 2> 1300409 INFO (qtp10275674-11742) [n:127.0.0.1:43357_solr c:addReplicaColl s:shard1 r:core_node1 x:addReplicaColl_shard1_replica_n1] o.a.s.s.SolrIndexSearcher Opening [Searcher@cde34d[addReplicaColl_shard1_replica_n1] main]
[junit4] 2> 1300409 INFO (qtp10275674-11742) [n:127.0.0.1:43357_solr c:addReplicaColl s:shard1 r:core_node1 x:addReplicaColl_shard1_replica_n1] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf
[junit4] 2> 1300410 INFO (qtp10275674-11742) [n:127.0.0.1:43357_solr c:addReplicaColl s:shard1 r:core_node1 x:addReplicaColl_shard1_replica_n1] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf
[junit4] 2> 1300410 INFO (qtp10275674-11742) [n:127.0.0.1:43357_solr c:addReplicaColl s:shard1 r:core_node1 x:addReplicaColl_shard1_replica_n1] o.a.s.h.ReplicationHandler Commits will be reserved for 10000
[junit4] 2> 1300411 INFO (qtp22071740-11724) [n:127.0.0.1:42951_solr c:addReplicaColl s:shard2 r:core_node4 x:addReplicaColl_shard2_replica_n2] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
[junit4] 2> 1300411 INFO (qtp22071740-11724) [n:127.0.0.1:42951_solr c:addReplicaColl s:shard2 r:core_node4 x:addReplicaColl_shard2_replica_n2] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 1300411 INFO (searcherExecutor-4029-thread-1-processing-n:127.0.0.1:43357_solr x:addReplicaColl_shard1_replica_n1 s:shard1 c:addReplicaColl r:core_node1) [n:127.0.0.1:43357_solr c:addReplicaColl s:shard1 r:core_node1 x:addReplicaColl_shard1_replica_n1] o.a.s.c.SolrCore [addReplicaColl_shard1_replica_n1] Registered new searcher Searcher@cde34d[addReplicaColl_shard1_replica_n1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 1300411 INFO (qtp10275674-11742) [n:127.0.0.1:43357_solr c:addReplicaColl s:shard1
[...truncated too long message...]
> 1378537 INFO (coreCloseExecutor-4208-thread-1) [n:127.0.0.1:41577_solr c:nodes_used_collection s:shard2 r:core_node3 x:nodes_used_collection_shard2_replica_n1] o.a.s.c.SolrCore [nodes_used_collection_shard2_replica_n1] CLOSING SolrCore org.apache.solr.core.SolrCore@86d484
[junit4] 2> 1378537 INFO (coreCloseExecutor-4208-thread-1) [n:127.0.0.1:41577_solr c:nodes_used_collection s:shard2 r:core_node3 x:nodes_used_collection_shard2_replica_n1] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.core.nodes_used_collection.shard2.replica_n1, tag=8836228
[junit4] 2> 1378537 INFO (coreCloseExecutor-4208-thread-1) [n:127.0.0.1:41577_solr c:nodes_used_collection s:shard2 r:core_node3 x:nodes_used_collection_shard2_replica_n1] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@37161b: rootName = null, domain = solr.core.nodes_used_collection.shard2.replica_n1, service url = null, agent id = null] for registry solr.core.nodes_used_collection.shard2.replica_n1 / com.codahale.metrics.MetricRegistry@1c537f6
[junit4] 2> 1378549 INFO (coreCloseExecutor-4208-thread-1) [n:127.0.0.1:41577_solr c:nodes_used_collection s:shard2 r:core_node3 x:nodes_used_collection_shard2_replica_n1] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.collection.nodes_used_collection.shard2.leader, tag=8836228
[junit4] 2> 1378549 INFO (coreCloseExecutor-4205-thread-1) [n:127.0.0.1:43357_solr c:nodes_used_collection s:shard1 r:core_node2 x:nodes_used_collection_shard1_replica_n2] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.collection.nodes_used_collection.shard1.leader, tag=29569657
[junit4] 2> 1378549 INFO (coreCloseExecutor-4206-thread-1) [n:127.0.0.1:40241_solr c:nodes_used_collection s:shard2 r:core_node4 x:nodes_used_collection_shard2_replica_n2] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.collection.nodes_used_collection.shard2.leader, tag=30710527
[junit4] 2> 1378550 INFO (coreCloseExecutor-4207-thread-1) [n:127.0.0.1:42951_solr c:nodes_used_collection s:shard1 r:core_node1 x:nodes_used_collection_shard1_replica_n1] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.collection.nodes_used_collection.shard1.leader, tag=14270704
[junit4] 2> 1378550 INFO (jetty-closer-1433-thread-1) [ ] o.a.s.c.Overseer Overseer (id=98755367785594891-127.0.0.1:43357_solr-n_0000000000) closing
[junit4] 2> 1378550 INFO (zkCallback-1454-thread-3-processing-n:127.0.0.1:42951_solr) [n:127.0.0.1:42951_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (4) -> (2)
[junit4] 2> 1378550 INFO (OverseerStateUpdate-98755367785594891-127.0.0.1:43357_solr-n_0000000000) [n:127.0.0.1:43357_solr ] o.a.s.c.Overseer Overseer Loop exiting : 127.0.0.1:43357_solr
[junit4] 2> 1378550 WARN (zkCallback-1454-thread-3-processing-n:127.0.0.1:42951_solr) [n:127.0.0.1:42951_solr ] o.a.s.c.c.ZkStateReader ZooKeeper watch triggered, but Solr cannot talk to ZK: [KeeperErrorCode = Session expired for /live_nodes]
[junit4] 2> 1378553 INFO (jetty-closer-1433-thread-4) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@1adf4bc{/solr,null,UNAVAILABLE}
[junit4] 2> 1380050 WARN (zkCallback-1452-thread-5-processing-n:127.0.0.1:40241_solr) [n:127.0.0.1:40241_solr ] o.a.s.c.c.ZkStateReader ZooKeeper watch triggered, but Solr cannot talk to ZK: [KeeperErrorCode = Session expired for /live_nodes]
[junit4] 2> 1380050 WARN (zkCallback-1483-thread-1-processing-n:127.0.0.1:41577_solr) [n:127.0.0.1:41577_solr ] o.a.s.c.c.ZkStateReader ZooKeeper watch triggered, but Solr cannot talk to ZK: [KeeperErrorCode = Session expired for /live_nodes]
[junit4] 2> 1380051 INFO (jetty-closer-1433-thread-2) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@5710ad{/solr,null,UNAVAILABLE}
[junit4] 2> 1380051 INFO (jetty-closer-1433-thread-3) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@1840a3c{/solr,null,UNAVAILABLE}
[junit4] 2> 1380053 WARN (zkCallback-1453-thread-5-processing-n:127.0.0.1:43357_solr) [n:127.0.0.1:43357_solr ] o.a.s.c.c.ZkStateReader ZooKeeper watch triggered, but Solr cannot talk to ZK: [KeeperErrorCode = Session expired for /live_nodes]
[junit4] 2> 1380053 INFO (jetty-closer-1433-thread-1) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@1803eec{/solr,null,UNAVAILABLE}
[junit4] 2> 1380054 ERROR (SUITE-CollectionsAPIDistributedZkTest-seed#[22F645446B8A6553]-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> 1380054 INFO (SUITE-CollectionsAPIDistributedZkTest-seed#[22F645446B8A6553]-worker) [ ] o.a.s.c.ZkTestServer connecting to 127.0.0.1:46533 46533
[junit4] 2> 1380066 INFO (Thread-3929) [ ] o.a.s.c.ZkTestServer connecting to 127.0.0.1:46533 46533
[junit4] 2> 1380068 WARN (Thread-3929) [ ] o.a.s.c.ZkTestServer Watch limit violations:
[junit4] 2> Maximum concurrent create/delete watches above limit:
[junit4] 2>
[junit4] 2> 10 /solr/configs/conf
[junit4] 2> 6 /solr/clusterprops.json
[junit4] 2> 6 /solr/aliases.json
[junit4] 2>
[junit4] 2> Maximum concurrent data watches above limit:
[junit4] 2>
[junit4] 2> 32 /solr/collections/nodes_used_collection/state.json
[junit4] 2> 30 /solr/collections/reloaded_collection/state.json
[junit4] 2> 8 /solr/collections/awhollynewcollection_0/state.json
[junit4] 2> 6 /solr/clusterstate.json
[junit4] 2> 5 /solr/collections/withconfigset2/state.json
[junit4] 2> 4 /solr/collections/halfcollectionblocker/state.json
[junit4] 2> 4 /solr/collections/halfcollection/state.json
[junit4] 2> 4 /solr/collections/halfcollectionblocker2/state.json
[junit4] 2>
[junit4] 2> Maximum concurrent children watches above limit:
[junit4] 2>
[junit4] 2> 238 /solr/collections
[junit4] 2> 6 /solr/live_nodes
[junit4] 2>
[junit4] 2> NOTE: leaving temporary files on disk at: /home/jenkins/workspace/Lucene-Solr-7.0-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.CollectionsAPIDistributedZkTest_22F645446B8A6553-001
[junit4] 2> Oct 01, 2017 7:50:11 PM com.carrotsearch.randomizedtesting.ThreadLeakControl checkThreadLeaks
[junit4] 2> WARNING: Will linger awaiting termination of 1 leaked thread(s).
[junit4] 2> NOTE: test params are: codec=Asserting(Lucene70): {id=PostingsFormat(name=Memory)}, docValues:{}, maxPointsInLeafNode=880, maxMBSortInHeap=5.368270160587303, sim=RandomSimilarity(queryNorm=true): {}, locale=fr-LU, timezone=America/Tegucigalpa
[junit4] 2> NOTE: Linux 4.10.0-33-generic i386/Oracle Corporation 1.8.0_144 (32-bit)/cpus=8,threads=1,free=145940304,total=417857536
[junit4] 2> NOTE: All tests run in this JVM: [SolrTestCaseJ4Test, BlockJoinFacetDistribTest, TestLockTree, SuggestComponentTest, CdcrReplicationDistributedZkTest, SpatialRPTFieldTypeTest, LeaderElectionContextKeyTest, DistributedFacetPivotSmallAdvancedTest, TestSuggestSpellingConverter, AsyncCallRequestStatusResponseTest, LeaderElectionTest, GraphQueryTest, HdfsRecoveryZkTest, TestClusterProperties, PreAnalyzedFieldTest, TestNumericTerms32, TestGroupingSearch, TestReloadDeadlock, TestSha256AuthenticationProvider, CircularListTest, TestStressReorder, ResponseHeaderTest, TestDocBasedVersionConstraints, DataDrivenBlockJoinTest, TestExactSharedStatsCache, TestSurroundQueryParser, CopyFieldTest, LargeFieldTest, TestMaxTokenLenTokenizer, SortSpecParsingTest, TestConfigSets, TestSort, RequiredFieldsTest, TestSchemaResource, BasicDistributedZk2Test, TestSolrXml, TestPayloadScoreQParserPlugin, CoreAdminCreateDiscoverTest, PrimitiveFieldTypeTest, TestAuthorizationFramework, DocumentBuilderTest, TestManagedResourceStorage, SolrCloudExampleTest, TlogReplayBufferedWhileIndexingTest, NotRequiredUniqueKeyTest, TestStressCloudBlindAtomicUpdates, TestInitParams, TestExclusionRuleCollectionAccess, CustomCollectionTest, TestHttpShardHandlerFactory, TestConfigOverlay, FastVectorHighlighterTest, TimeZoneUtilsTest, TestQuerySenderListener, CollectionsAPIAsyncDistributedZkTest, HdfsBasicDistributedZkTest, SaslZkACLProviderTest, TestSegmentSorting, MultiTermTest, SolrCoreCheckLockOnStartupTest, TestCloudDeleteByQuery, HdfsLockFactoryTest, SignatureUpdateProcessorFactoryTest, TestGeoJSONResponseWriter, HdfsWriteToMultipleCollectionsTest, TestSystemCollAutoCreate, SharedFSAutoReplicaFailoverUtilsTest, TestTlogReplica, TestTrie, TestJsonFacetRefinement, AnalyticsMergeStrategyTest, DeleteStatusTest, MissingSegmentRecoveryTest, DateMathParserTest, ConfigSetsAPITest, TestTrieFacet, IgnoreCommitOptimizeUpdateProcessorFactoryTest, HdfsDirectoryFactoryTest, SimplePostToolTest, TestLegacyNumericUtils, VersionInfoTest, ActionThrottleTest, TestMaxScoreQueryParser, OverseerTaskQueueTest, TestMacros, SpellPossibilityIteratorTest, TestDynamicFieldResource, ReturnFieldsTest, ClusterStateTest, DirectUpdateHandlerTest, TestApiFramework, TestConfigSetsAPIExclusivity, TestDFRSimilarityFactory, TestScoreJoinQPNoScore, BasicAuthIntegrationTest, TestInPlaceUpdatesDistrib, OutOfBoxZkACLAndCredentialsProvidersTest, TestOrdValues, TestFieldTypeCollectionResource, TestSolrCloudWithHadoopAuthPlugin, TestFieldCacheReopen, TestSubQueryTransformerCrossCore, TestAnalyzeInfixSuggestions, HardAutoCommitTest, TestHalfAndHalfDocValues, TestBinaryResponseWriter, TestSolrCloudWithDelegationTokens, TestDynamicLoading, TestPushWriter, TestPullReplica, ResponseLogComponentTest, FullSolrCloudDistribCmdsTest, TestLFUCache, JavabinLoaderTest, PingRequestHandlerTest, SortByFunctionTest, CollectionsAPIDistributedZkTest]
[junit4] Completed [329/730 (1!)] on J2 in 86.34s, 19 tests, 1 error <<< FAILURES!
[...truncated 41025 lines...]
[JENKINS] Lucene-Solr-7.0-Linux (64bit/jdk-9) - Build # 404 - Still
Unstable!
Posted by Policeman Jenkins Server <je...@thetaphi.de>.
Build: https://jenkins.thetaphi.de/job/Lucene-Solr-7.0-Linux/404/
Java: 64bit/jdk-9 -XX:+UseCompressedOops -XX:+UseSerialGC --illegal-access=deny
1 tests failed.
FAILED: org.apache.solr.cloud.TestSolrCloudWithDelegationTokens.testDelegationTokenRenew
Error Message:
expected:<200> but was:<403>
Stack Trace:
java.lang.AssertionError: expected:<200> but was:<403>
at __randomizedtesting.SeedInfo.seed([ABDB6305EAF3FAEB:9C40971BD23F274F]:0)
at org.junit.Assert.fail(Assert.java:93)
at org.junit.Assert.failNotEquals(Assert.java:647)
at org.junit.Assert.assertEquals(Assert.java:128)
at org.junit.Assert.assertEquals(Assert.java:472)
at org.junit.Assert.assertEquals(Assert.java:456)
at org.apache.solr.cloud.TestSolrCloudWithDelegationTokens.renewDelegationToken(TestSolrCloudWithDelegationTokens.java:130)
at org.apache.solr.cloud.TestSolrCloudWithDelegationTokens.verifyDelegationTokenRenew(TestSolrCloudWithDelegationTokens.java:316)
at org.apache.solr.cloud.TestSolrCloudWithDelegationTokens.testDelegationTokenRenew(TestSolrCloudWithDelegationTokens.java:333)
at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.base/java.lang.reflect.Method.invoke(Method.java:564)
at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1713)
at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:907)
at com.carrotsearch.randomizedtesting.RandomizedRunner$9.evaluate(RandomizedRunner.java:943)
at com.carrotsearch.randomizedtesting.RandomizedRunner$10.evaluate(RandomizedRunner.java:957)
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:916)
at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:802)
at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:852)
at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:863)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:41)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:53)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:54)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368)
at java.base/java.lang.Thread.run(Thread.java:844)
Build Log:
[...truncated 11855 lines...]
[junit4] Suite: org.apache.solr.cloud.TestSolrCloudWithDelegationTokens
[junit4] 2> Creating dataDir: /home/jenkins/workspace/Lucene-Solr-7.0-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.TestSolrCloudWithDelegationTokens_ABDB6305EAF3FAEB-001/init-core-data-001
[junit4] 2> 731851 WARN (SUITE-TestSolrCloudWithDelegationTokens-seed#[ABDB6305EAF3FAEB]-worker) [ ] o.a.s.SolrTestCaseJ4 startTrackingSearchers: numOpens=1 numCloses=1
[junit4] 2> 731851 INFO (SUITE-TestSolrCloudWithDelegationTokens-seed#[ABDB6305EAF3FAEB]-worker) [ ] o.a.s.SolrTestCaseJ4 Using PointFields (NUMERIC_POINTS_SYSPROP=true) w/NUMERIC_DOCVALUES_SYSPROP=false
[junit4] 2> 731852 INFO (SUITE-TestSolrCloudWithDelegationTokens-seed#[ABDB6305EAF3FAEB]-worker) [ ] o.a.s.SolrTestCaseJ4 Randomized ssl (true) and clientAuth (true) via: @org.apache.solr.util.RandomizeSSL(reason="", ssl=0.0/0.0, value=0.0/0.0, clientAuth=0.0/0.0)
[junit4] 2> 731854 INFO (SUITE-TestSolrCloudWithDelegationTokens-seed#[ABDB6305EAF3FAEB]-worker) [ ] o.a.s.c.MiniSolrCloudCluster Starting cluster of 2 servers in /home/jenkins/workspace/Lucene-Solr-7.0-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.TestSolrCloudWithDelegationTokens_ABDB6305EAF3FAEB-001/tempDir-001
[junit4] 2> 731854 INFO (SUITE-TestSolrCloudWithDelegationTokens-seed#[ABDB6305EAF3FAEB]-worker) [ ] o.a.s.c.ZkTestServer STARTING ZK TEST SERVER
[junit4] 2> 731854 INFO (Thread-1371) [ ] o.a.s.c.ZkTestServer client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 731855 INFO (Thread-1371) [ ] o.a.s.c.ZkTestServer Starting server
[junit4] 2> 731856 ERROR (Thread-1371) [ ] 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> 731954 INFO (SUITE-TestSolrCloudWithDelegationTokens-seed#[ABDB6305EAF3FAEB]-worker) [ ] o.a.s.c.ZkTestServer start zk server on port:40159
[junit4] 2> 731961 INFO (jetty-launcher-933-thread-1) [ ] o.e.j.s.Server jetty-9.3.14.v20161028
[junit4] 2> 731961 INFO (jetty-launcher-933-thread-2) [ ] o.e.j.s.Server jetty-9.3.14.v20161028
[junit4] 2> 731973 INFO (jetty-launcher-933-thread-1) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@2a7070e8{/solr,null,AVAILABLE}
[junit4] 2> 731977 INFO (jetty-launcher-933-thread-2) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@381fff36{/solr,null,AVAILABLE}
[junit4] 2> 731979 INFO (jetty-launcher-933-thread-1) [ ] o.e.j.s.AbstractConnector Started ServerConnector@62c3d621{SSL,[ssl, http/1.1]}{127.0.0.1:35647}
[junit4] 2> 731979 INFO (jetty-launcher-933-thread-1) [ ] o.e.j.s.Server Started @734006ms
[junit4] 2> 731979 INFO (jetty-launcher-933-thread-1) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=35647}
[junit4] 2> 731979 INFO (jetty-launcher-933-thread-2) [ ] o.e.j.s.AbstractConnector Started ServerConnector@70daddb2{SSL,[ssl, http/1.1]}{127.0.0.1:40799}
[junit4] 2> 731979 INFO (jetty-launcher-933-thread-2) [ ] o.e.j.s.Server Started @734007ms
[junit4] 2> 731979 INFO (jetty-launcher-933-thread-2) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=40799}
[junit4] 2> 731979 ERROR (jetty-launcher-933-thread-2) [ ] o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 731979 INFO (jetty-launcher-933-thread-2) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version 7.0.1
[junit4] 2> 731979 INFO (jetty-launcher-933-thread-2) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 731979 INFO (jetty-launcher-933-thread-2) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null, Default config dir: null
[junit4] 2> 731979 INFO (jetty-launcher-933-thread-2) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2017-10-02T00:20:28.296718Z
[junit4] 2> 731979 ERROR (jetty-launcher-933-thread-1) [ ] o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 731980 INFO (jetty-launcher-933-thread-1) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version 7.0.1
[junit4] 2> 731980 INFO (jetty-launcher-933-thread-1) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 731980 INFO (jetty-launcher-933-thread-1) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null, Default config dir: null
[junit4] 2> 731980 INFO (jetty-launcher-933-thread-1) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2017-10-02T00:20:28.297167Z
[junit4] 2> 731987 INFO (jetty-launcher-933-thread-2) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 731987 INFO (jetty-launcher-933-thread-1) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 731991 INFO (jetty-launcher-933-thread-2) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:40159/solr
[junit4] 2> 731998 INFO (jetty-launcher-933-thread-1) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:40159/solr
[junit4] 2> 732024 INFO (jetty-launcher-933-thread-1) [ ] o.a.s.c.Overseer Overseer (id=null) closing
[junit4] 2> 732025 INFO (jetty-launcher-933-thread-1) [ ] o.a.s.c.OverseerElectionContext I am going to be the leader 127.0.0.1:35647_solr
[junit4] 2> 732025 INFO (jetty-launcher-933-thread-1) [ ] o.a.s.c.Overseer Overseer (id=98756436175945734-127.0.0.1:35647_solr-n_0000000000) starting
[junit4] 2> 732046 INFO (jetty-launcher-933-thread-1) [ ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:35647_solr
[junit4] 2> 732053 INFO (zkCallback-945-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 732056 INFO (jetty-launcher-933-thread-2) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 732061 INFO (jetty-launcher-933-thread-2) [ ] o.a.s.c.Overseer Overseer (id=null) closing
[junit4] 2> 732062 INFO (jetty-launcher-933-thread-2) [ ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:40799_solr
[junit4] 2> 732064 INFO (zkCallback-941-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
[junit4] 2> 732073 INFO (zkCallback-945-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
[junit4] 2> 732083 INFO (jetty-launcher-933-thread-2) [ ] o.a.s.c.CoreContainer Initializing authentication plugin: org.apache.solr.security.HttpParamDelegationTokenPlugin
[junit4] 2> 732086 WARN (jetty-launcher-933-thread-2) [ ] o.a.s.c.s.i.Krb5HttpClientBuilder org.apache.solr.client.solrj.impl.Krb5HttpClientBuilder is configured without specifying system property 'java.security.auth.login.config'
[junit4] 2> 732089 INFO (jetty-launcher-933-thread-2) [ ] o.a.s.s.KerberosPlugin Params: {token.valid=30, delegation-token.token-kind=solr-dt, cookie.domain=127.0.0.1, cookie.path=/, zk-dt-secret-manager.znodeWorkingPath=solr/security/zkdtsm, token.validity=36000, signer.secret.provider.zookeeper.path=/token, type=kerberos, zk-dt-secret-manager.enable=true, kerberos.name.rules=DEFAULT, signer.secret.provider=zookeeper}
[junit4] 2> 732097 INFO (jetty-launcher-933-thread-1) [ ] o.a.s.c.CoreContainer Initializing authentication plugin: org.apache.solr.security.HttpParamDelegationTokenPlugin
[junit4] 2> 732097 WARN (jetty-launcher-933-thread-1) [ ] o.a.s.c.s.i.Krb5HttpClientBuilder org.apache.solr.client.solrj.impl.Krb5HttpClientBuilder is configured without specifying system property 'java.security.auth.login.config'
[junit4] 2> 732098 INFO (jetty-launcher-933-thread-1) [ ] o.a.s.s.KerberosPlugin Params: {token.valid=30, delegation-token.token-kind=solr-dt, cookie.domain=127.0.0.1, cookie.path=/, zk-dt-secret-manager.znodeWorkingPath=solr/security/zkdtsm, token.validity=36000, signer.secret.provider.zookeeper.path=/token, type=kerberos, zk-dt-secret-manager.enable=true, kerberos.name.rules=DEFAULT, signer.secret.provider=zookeeper}
[junit4] 2> 732117 INFO (jetty-launcher-933-thread-2) [ ] o.a.c.f.i.CuratorFrameworkImpl Starting
[junit4] 2> 732117 INFO (jetty-launcher-933-thread-1) [ ] o.a.c.f.i.CuratorFrameworkImpl Starting
[junit4] 2> 732125 INFO (jetty-launcher-933-thread-2-EventThread) [ ] o.a.c.f.s.ConnectionStateManager State change: CONNECTED
[junit4] 2> 732125 INFO (jetty-launcher-933-thread-1-EventThread) [ ] o.a.c.f.s.ConnectionStateManager State change: CONNECTED
[junit4] 2> 732175 WARN (jetty-launcher-933-thread-2) [ ] o.a.s.c.s.i.Krb5HttpClientBuilder org.apache.solr.client.solrj.impl.Krb5HttpClientBuilder is configured without specifying system property 'java.security.auth.login.config'
[junit4] 2> 732180 WARN (jetty-launcher-933-thread-1) [ ] o.a.s.c.s.i.Krb5HttpClientBuilder org.apache.solr.client.solrj.impl.Krb5HttpClientBuilder is configured without specifying system property 'java.security.auth.login.config'
[junit4] 2> 732213 INFO (jetty-launcher-933-thread-2) [ ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_40799.solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@3fba2b14
[junit4] 2> 732220 INFO (jetty-launcher-933-thread-1) [ ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_35647.solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@3fba2b14
[junit4] 2> 732221 INFO (jetty-launcher-933-thread-2) [ ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_40799.solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@3fba2b14
[junit4] 2> 732221 INFO (jetty-launcher-933-thread-2) [ ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_40799.solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@3fba2b14
[junit4] 2> 732222 INFO (jetty-launcher-933-thread-2) [ ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /home/jenkins/workspace/Lucene-Solr-7.0-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.TestSolrCloudWithDelegationTokens_ABDB6305EAF3FAEB-001/tempDir-001/node2/.
[junit4] 2> 732225 INFO (jetty-launcher-933-thread-1) [ ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_35647.solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@3fba2b14
[junit4] 2> 732225 INFO (jetty-launcher-933-thread-1) [ ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_35647.solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@3fba2b14
[junit4] 2> 732226 INFO (jetty-launcher-933-thread-1) [ ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /home/jenkins/workspace/Lucene-Solr-7.0-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.TestSolrCloudWithDelegationTokens_ABDB6305EAF3FAEB-001/tempDir-001/node1/.
[junit4] 2> 732257 INFO (TEST-TestSolrCloudWithDelegationTokens.testDelegationTokenRenew-seed#[ABDB6305EAF3FAEB]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testDelegationTokenRenew
[junit4] 2> 732284 WARN (qtp184495212-6036) [ ] o.a.h.s.a.s.AuthenticationFilter Authentication exception: org.apache.hadoop.security.AccessControlException: bar is trying to renew a token with wrong password
[junit4] 2> 732288 WARN (qtp184495212-6036) [ ] o.a.s.s.KerberosPlugin Could not find org.apache.solr.security.authentication.requestcontinues
[junit4] 2> 732292 WARN (TEST-TestSolrCloudWithDelegationTokens.testDelegationTokenRenew-seed#[ABDB6305EAF3FAEB]) [ ] o.a.h.c.p.ResponseProcessCookies Invalid cookie header: "Set-Cookie: hadoop.auth=; Path=/; Domain=127.0.0.1; Expires=jeu., 01-janv.-1970 00:00:00 GMT; Secure; HttpOnly". Invalid 'expires' attribute: jeu., 01-janv.-1970 00:00:00 GMT
[junit4] 2> 732292 INFO (TEST-TestSolrCloudWithDelegationTokens.testDelegationTokenRenew-seed#[ABDB6305EAF3FAEB]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testDelegationTokenRenew
[junit4] 2> NOTE: reproduce with: ant test -Dtestcase=TestSolrCloudWithDelegationTokens -Dtests.method=testDelegationTokenRenew -Dtests.seed=ABDB6305EAF3FAEB -Dtests.multiplier=3 -Dtests.slow=true -Dtests.locale=fr-YT -Dtests.timezone=Asia/Urumqi -Dtests.asserts=true -Dtests.file.encoding=US-ASCII
[junit4] FAILURE 0.04s J2 | TestSolrCloudWithDelegationTokens.testDelegationTokenRenew <<<
[junit4] > Throwable #1: java.lang.AssertionError: expected:<200> but was:<403>
[junit4] > at __randomizedtesting.SeedInfo.seed([ABDB6305EAF3FAEB:9C40971BD23F274F]:0)
[junit4] > at org.apache.solr.cloud.TestSolrCloudWithDelegationTokens.renewDelegationToken(TestSolrCloudWithDelegationTokens.java:130)
[junit4] > at org.apache.solr.cloud.TestSolrCloudWithDelegationTokens.verifyDelegationTokenRenew(TestSolrCloudWithDelegationTokens.java:316)
[junit4] > at org.apache.solr.cloud.TestSolrCloudWithDelegationTokens.testDelegationTokenRenew(TestSolrCloudWithDelegationTokens.java:333)
[junit4] > at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
[junit4] > at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
[junit4] > at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
[junit4] > at java.base/java.lang.reflect.Method.invoke(Method.java:564)
[junit4] > at java.base/java.lang.Thread.run(Thread.java:844)
[junit4] 2> 732300 INFO (TEST-TestSolrCloudWithDelegationTokens.testDelegationTokenSolrClient-seed#[ABDB6305EAF3FAEB]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testDelegationTokenSolrClient
[junit4] 2> 732306 WARN (TEST-TestSolrCloudWithDelegationTokens.testDelegationTokenSolrClient-seed#[ABDB6305EAF3FAEB]) [ ] o.a.h.c.p.ResponseProcessCookies Invalid cookie header: "Set-Cookie: hadoop.auth=; Path=/; Domain=127.0.0.1; Expires=jeu., 01-janv.-1970 00:00:00 GMT; Secure; HttpOnly". Invalid 'expires' attribute: jeu., 01-janv.-1970 00:00:00 GMT
[junit4] 2> 732314 INFO (qtp184495212-6030) [ ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :list with params action=LIST&delegation=GgADYmFyA2JhcgCKAV7adJtJigFe_oEfSQIEFCmsTvgV-R2aQIj_RY3vXJECoGwkB3NvbHItZHQA&wt=javabin&version=2 and sendToOCPQueue=true
[junit4] 2> 732314 INFO (qtp184495212-6030) [ ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={action=LIST&delegation=GgADYmFyA2JhcgCKAV7adJtJigFe_oEfSQIEFCmsTvgV-R2aQIj_RY3vXJECoGwkB3NvbHItZHQA&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 732315 INFO (TEST-TestSolrCloudWithDelegationTokens.testDelegationTokenSolrClient-seed#[ABDB6305EAF3FAEB]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testDelegationTokenSolrClient
[junit4] IGNOR/A 0.00s J2 | TestSolrCloudWithDelegationTokens.testDelegationTokenCancelFail
[junit4] > Assumption #1: 'awaitsfix' test group is disabled (@AwaitsFix(bugUrl="https://issues.apache.org/jira/browse/HADOOP-14044"))
[junit4] 2> 732323 INFO (TEST-TestSolrCloudWithDelegationTokens.testDelegationOtherOp-seed#[ABDB6305EAF3FAEB]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testDelegationOtherOp
[junit4] 2> 732325 INFO (TEST-TestSolrCloudWithDelegationTokens.testDelegationOtherOp-seed#[ABDB6305EAF3FAEB]) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (2)
[junit4] 2> 732325 INFO (TEST-TestSolrCloudWithDelegationTokens.testDelegationOtherOp-seed#[ABDB6305EAF3FAEB]) [ ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:40159/solr ready
[junit4] 2> 732328 INFO (qtp184495212-6030) [ ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :list with params op=someSolrOperation&action=LIST&wt=javabin&version=2 and sendToOCPQueue=true
[junit4] 2> 732328 INFO (qtp184495212-6030) [ ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={op=someSolrOperation&action=LIST&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 732329 WARN (TEST-TestSolrCloudWithDelegationTokens.testDelegationOtherOp-seed#[ABDB6305EAF3FAEB]) [ ] o.a.h.c.p.ResponseProcessCookies Invalid cookie header: "Set-Cookie: hadoop.auth="u=bar&p=bar&t=test&e=1506939628644&s=GAiSpaj7UsowpPY5+iV79536zvA="; Path=/; Domain=127.0.0.1; Expires=lun., 02-oct.-2017 10:20:28 GMT; Secure; HttpOnly". Invalid 'expires' attribute: lun., 02-oct.-2017 10:20:28 GMT
[junit4] 2> 732330 INFO (TEST-TestSolrCloudWithDelegationTokens.testDelegationOtherOp-seed#[ABDB6305EAF3FAEB]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testDelegationOtherOp
[junit4] 2> 732339 INFO (TEST-TestSolrCloudWithDelegationTokens.testDelegationTokenCancel-seed#[ABDB6305EAF3FAEB]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testDelegationTokenCancel
[junit4] 2> 732360 ERROR (qtp184495212-6028) [ ] o.a.h.s.t.d.ZKDelegationTokenSecretManager No node in path [/ZKDTSMTokensRoot/DT_3]
[junit4] 2> 732365 INFO (TEST-TestSolrCloudWithDelegationTokens.testDelegationTokenCancel-seed#[ABDB6305EAF3FAEB]) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (2)
[junit4] 2> 732365 INFO (TEST-TestSolrCloudWithDelegationTokens.testDelegationTokenCancel-seed#[ABDB6305EAF3FAEB]) [ ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:40159/solr ready
[junit4] 2> 732367 WARN (TEST-TestSolrCloudWithDelegationTokens.testDelegationTokenCancel-seed#[ABDB6305EAF3FAEB]) [ ] o.a.h.c.p.ResponseProcessCookies Invalid cookie header: "Set-Cookie: hadoop.auth=; Path=/; Domain=127.0.0.1; Expires=jeu., 01-janv.-1970 00:00:00 GMT; Secure; HttpOnly". Invalid 'expires' attribute: jeu., 01-janv.-1970 00:00:00 GMT
[junit4] 2> 732370 INFO (TEST-TestSolrCloudWithDelegationTokens.testDelegationTokenCancel-seed#[ABDB6305EAF3FAEB]) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (2)
[junit4] 2> 732371 INFO (TEST-TestSolrCloudWithDelegationTokens.testDelegationTokenCancel-seed#[ABDB6305EAF3FAEB]) [ ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:40159/solr ready
[junit4] 2> 732372 WARN (TEST-TestSolrCloudWithDelegationTokens.testDelegationTokenCancel-seed#[ABDB6305EAF3FAEB]) [ ] o.a.h.c.p.ResponseProcessCookies Invalid cookie header: "Set-Cookie: hadoop.auth=; Path=/; Domain=127.0.0.1; Expires=jeu., 01-janv.-1970 00:00:00 GMT; Secure; HttpOnly". Invalid 'expires' attribute: jeu., 01-janv.-1970 00:00:00 GMT
[junit4] 2> 732397 ERROR (qtp2026701416-6037) [ ] o.a.h.s.t.d.ZKDelegationTokenSecretManager No node in path [/ZKDTSMTokensRoot/DT_4]
[junit4] 2> 732402 WARN (TEST-TestSolrCloudWithDelegationTokens.testDelegationTokenCancel-seed#[ABDB6305EAF3FAEB]) [ ] o.a.h.c.p.ResponseProcessCookies Invalid cookie header: "Set-Cookie: hadoop.auth=; Path=/; Domain=127.0.0.1; Expires=jeu., 01-janv.-1970 00:00:00 GMT; Secure; HttpOnly". Invalid 'expires' attribute: jeu., 01-janv.-1970 00:00:00 GMT
[junit4] 2> 732406 INFO (TEST-TestSolrCloudWithDelegationTokens.testDelegationTokenCancel-seed#[ABDB6305EAF3FAEB]) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (2)
[junit4] 2> 732407 INFO (TEST-TestSolrCloudWithDelegationTokens.testDelegationTokenCancel-seed#[ABDB6305EAF3FAEB]) [ ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:40159/solr ready
[junit4] 2> 732410 WARN (TEST-TestSolrCloudWithDelegationTokens.testDelegationTokenCancel-seed#[ABDB6305EAF3FAEB]) [ ] o.a.h.c.p.ResponseProcessCookies Invalid cookie header: "Set-Cookie: hadoop.auth=; Path=/; Domain=127.0.0.1; Expires=jeu., 01-janv.-1970 00:00:00 GMT; Secure; HttpOnly". Invalid 'expires' attribute: jeu., 01-janv.-1970 00:00:00 GMT
[junit4] 2> 732410 INFO (TEST-TestSolrCloudWithDelegationTokens.testDelegationTokenCancel-seed#[ABDB6305EAF3FAEB]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testDelegationTokenCancel
[junit4] 2> 732420 INFO (TEST-TestSolrCloudWithDelegationTokens.testDelegationTokenRenewFail-seed#[ABDB6305EAF3FAEB]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testDelegationTokenRenewFail
[junit4] 2> 732423 WARN (qtp184495212-6026) [ ] o.a.h.s.a.s.AuthenticationFilter Authentication exception: org.apache.hadoop.security.AccessControlException: foo tries to renew a token with renewer bar
[junit4] 2> 732424 WARN (qtp184495212-6026) [ ] o.a.s.s.KerberosPlugin Could not find org.apache.solr.security.authentication.requestcontinues
[junit4] 2> 732424 WARN (TEST-TestSolrCloudWithDelegationTokens.testDelegationTokenRenewFail-seed#[ABDB6305EAF3FAEB]) [ ] o.a.h.c.p.ResponseProcessCookies Invalid cookie header: "Set-Cookie: hadoop.auth=; Path=/; Domain=127.0.0.1; Expires=jeu., 01-janv.-1970 00:00:00 GMT; Secure; HttpOnly". Invalid 'expires' attribute: jeu., 01-janv.-1970 00:00:00 GMT
[junit4] 2> 732424 WARN (qtp2026701416-6033) [ ] o.a.h.s.a.s.AuthenticationFilter Authentication exception: org.apache.hadoop.security.AccessControlException: foo tries to renew a token with renewer bar
[junit4] 2> 732425 WARN (qtp2026701416-6033) [ ] o.a.s.s.KerberosPlugin Could not find org.apache.solr.security.authentication.requestcontinues
[junit4] 2> 732429 WARN (TEST-TestSolrCloudWithDelegationTokens.testDelegationTokenRenewFail-seed#[ABDB6305EAF3FAEB]) [ ] o.a.h.c.p.ResponseProcessCookies Invalid cookie header: "Set-Cookie: hadoop.auth=; Path=/; Domain=127.0.0.1; Expires=jeu., 01-janv.-1970 00:00:00 GMT; Secure; HttpOnly". Invalid 'expires' attribute: jeu., 01-janv.-1970 00:00:00 GMT
[junit4] 2> 732434 WARN (qtp184495212-6032) [ ] o.a.h.s.a.s.AuthenticationFilter Authentication exception: org.apache.hadoop.security.AccessControlException: notRenewUser tries to renew a token with renewer renewUser
[junit4] 2> 732434 WARN (qtp184495212-6032) [ ] o.a.s.s.KerberosPlugin Could not find org.apache.solr.security.authentication.requestcontinues
[junit4] 2> 732434 WARN (TEST-TestSolrCloudWithDelegationTokens.testDelegationTokenRenewFail-seed#[ABDB6305EAF3FAEB]) [ ] o.a.h.c.p.ResponseProcessCookies Invalid cookie header: "Set-Cookie: hadoop.auth=; Path=/; Domain=127.0.0.1; Expires=jeu., 01-janv.-1970 00:00:00 GMT; Secure; HttpOnly". Invalid 'expires' attribute: jeu., 01-janv.-1970 00:00:00 GMT
[junit4] 2> 732435 WARN (qtp2026701416-6037) [ ] o.a.h.s.a.s.AuthenticationFilter Authentication exception: org.apache.hadoop.security.AccessControlException: notRenewUser tries to renew a token with renewer renewUser
[junit4] 2> 732435 WARN (qtp2026701416-6037) [ ] o.a.s.s.KerberosPlugin Could not find org.apache.solr.security.authentication.requestcontinues
[junit4] 2> 732435 WARN (TEST-TestSolrCloudWithDelegationTokens.testDelegationTokenRenewFail-seed#[ABDB6305EAF3FAEB]) [ ] o.a.h.c.p.ResponseProcessCookies Invalid cookie header: "Set-Cookie: hadoop.auth=; Path=/; Domain=127.0.0.1; Expires=jeu., 01-janv.-1970 00:00:00 GMT; Secure; HttpOnly". Invalid 'expires' attribute: jeu., 01-janv.-1970 00:00:00 GMT
[junit4] 2> 732436 INFO (TEST-TestSolrCloudWithDelegationTokens.testDelegationTokenRenewFail-seed#[ABDB6305EAF3FAEB]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testDelegationTokenRenewFail
[junit4] 2> 732446 INFO (TEST-TestSolrCloudWithDelegationTokens.testDelegationTokenVerify-seed#[ABDB6305EAF3FAEB]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testDelegationTokenVerify
[junit4] 2> 732460 INFO (qtp184495212-6028) [ ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :list with params action=LIST&delegation=GgADYmFyA2JhcgCKAV7adJvbigFe_oEf2wcEFC3JVOApPh5QxTKdmSQX0C_ct9OeB3NvbHItZHQA&wt=javabin&version=2 and sendToOCPQueue=true
[junit4] 2> 732460 INFO (qtp184495212-6028) [ ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={action=LIST&delegation=GgADYmFyA2JhcgCKAV7adJvbigFe_oEf2wcEFC3JVOApPh5QxTKdmSQX0C_ct9OeB3NvbHItZHQA&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 732470 INFO (TEST-TestSolrCloudWithDelegationTokens.testDelegationTokenVerify-seed#[ABDB6305EAF3FAEB]) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (2)
[junit4] 2> 732470 INFO (TEST-TestSolrCloudWithDelegationTokens.testDelegationTokenVerify-seed#[ABDB6305EAF3FAEB]) [ ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:40159/solr ready
[junit4] 2> 732475 WARN (TEST-TestSolrCloudWithDelegationTokens.testDelegationTokenVerify-seed#[ABDB6305EAF3FAEB]) [ ] o.a.h.c.p.ResponseProcessCookies Invalid cookie header: "Set-Cookie: hadoop.auth=; Path=/; Domain=127.0.0.1; Expires=jeu., 01-janv.-1970 00:00:00 GMT; Secure; HttpOnly". Invalid 'expires' attribute: jeu., 01-janv.-1970 00:00:00 GMT
[junit4] 2> 732487 INFO (qtp2026701416-6024) [ ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :list with params action=LIST&delegation=GgADYmFyA2JhcgCKAV7adJvbigFe_oEf2wcEFC3JVOApPh5QxTKdmSQX0C_ct9OeB3NvbHItZHQA&wt=javabin&version=2 and sendToOCPQueue=true
[junit4] 2> 732488 INFO (qtp2026701416-6024) [ ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={action=LIST&delegation=GgADYmFyA2JhcgCKAV7adJvbigFe_oEf2wcEFC3JVOApPh5QxTKdmSQX0C_ct9OeB3NvbHItZHQA&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 732500 INFO (TEST-TestSolrCloudWithDelegationTokens.testDelegationTokenVerify-seed#[ABDB6305EAF3FAEB]) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (2)
[junit4] 2> 732500 INFO (TEST-TestSolrCloudWithDelegationTokens.testDelegationTokenVerify-seed#[ABDB6305EAF3FAEB]) [ ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:40159/solr ready
[junit4] 2> 732504 WARN (TEST-TestSolrCloudWithDelegationTokens.testDelegationTokenVerify-seed#[ABDB6305EAF3FAEB]) [ ] o.a.h.c.p.ResponseProcessCookies Invalid cookie header: "Set-Cookie: hadoop.auth=; Path=/; Domain=127.0.0.1; Expires=jeu., 01-janv.-1970 00:00:00 GMT; Secure; HttpOnly". Invalid 'expires' attribute: jeu., 01-janv.-1970 00:00:00 GMT
[junit4] 2> 732509 INFO (TEST-TestSolrCloudWithDelegationTokens.testDelegationTokenVerify-seed#[ABDB6305EAF3FAEB]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testDelegationTokenVerify
[junit4] 2> 732521 INFO (TEST-TestSolrCloudWithDelegationTokens.testZNodePaths-seed#[ABDB6305EAF3FAEB]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testZNodePaths
[junit4] 2> 732530 INFO (TEST-TestSolrCloudWithDelegationTokens.testZNodePaths-seed#[ABDB6305EAF3FAEB]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testZNodePaths
[junit4] 2> 732534 INFO (jetty-closer-934-thread-1) [ ] o.e.j.s.AbstractConnector Stopped ServerConnector@70daddb2{SSL,[ssl, http/1.1]}{127.0.0.1:0}
[junit4] 2> 732534 INFO (jetty-closer-934-thread-1) [ ] o.a.s.c.CoreContainer Shutting down CoreContainer instance=1361823536
[junit4] 2> 732534 INFO (jetty-closer-934-thread-1) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.node, tag=null
[junit4] 2> 732534 INFO (jetty-closer-934-thread-1) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@20acf35b: rootName = solr_40799, domain = solr.node, service url = null, agent id = null] for registry solr.node / com.codahale.metrics.MetricRegistry@667f6aa9
[junit4] 2> 732535 INFO (jetty-closer-934-thread-2) [ ] o.e.j.s.AbstractConnector Stopped ServerConnector@62c3d621{SSL,[ssl, http/1.1]}{127.0.0.1:0}
[junit4] 2> 732535 INFO (jetty-closer-934-thread-2) [ ] o.a.s.c.CoreContainer Shutting down CoreContainer instance=1674214090
[junit4] 2> 732535 INFO (jetty-closer-934-thread-2) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.node, tag=null
[junit4] 2> 732535 INFO (jetty-closer-934-thread-2) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@4fe44aec: rootName = solr_35647, domain = solr.node, service url = null, agent id = null] for registry solr.node / com.codahale.metrics.MetricRegistry@6355bdfc
[junit4] 2> 732538 INFO (jetty-closer-934-thread-1) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jvm, tag=null
[junit4] 2> 732538 INFO (jetty-closer-934-thread-1) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@2a76f346: rootName = solr_40799, domain = solr.jvm, service url = null, agent id = null] for registry solr.jvm / com.codahale.metrics.MetricRegistry@7dd0681c
[junit4] 2> 732539 INFO (jetty-closer-934-thread-2) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jvm, tag=null
[junit4] 2> 732539 INFO (jetty-closer-934-thread-2) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@4f8b31e2: rootName = solr_35647, domain = solr.jvm, service url = null, agent id = null] for registry solr.jvm / com.codahale.metrics.MetricRegistry@7dd0681c
[junit4] 2> 732541 INFO (jetty-closer-934-thread-2) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jetty, tag=null
[junit4] 2> 732541 INFO (jetty-closer-934-thread-2) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@48bb0e6b: rootName = solr_35647, domain = solr.jetty, service url = null, agent id = null] for registry solr.jetty / com.codahale.metrics.MetricRegistry@79c8fbd1
[junit4] 2> 732542 INFO (jetty-closer-934-thread-1) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jetty, tag=null
[junit4] 2> 732542 INFO (jetty-closer-934-thread-1) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@68feebfa: rootName = solr_40799, domain = solr.jetty, service url = null, agent id = null] for registry solr.jetty / com.codahale.metrics.MetricRegistry@79c8fbd1
[junit4] 2> 732546 INFO (jetty-closer-934-thread-1) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.cluster, tag=null
[junit4] 2> 732546 INFO (jetty-closer-934-thread-1) [ ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores
[junit4] 2> 732546 WARN (zkCallback-941-thread-1) [ ] o.a.s.c.c.ZkStateReader ZooKeeper watch triggered, but Solr cannot talk to ZK: [KeeperErrorCode = Session expired for /live_nodes]
[junit4] 2> 732546 ERROR (Thread[Thread-1388,5,TGRP-TestSolrCloudWithDelegationTokens]) [ ] o.a.h.s.t.d.AbstractDelegationTokenSecretManager ExpiredTokenRemover received java.lang.InterruptedException: sleep interrupted
[junit4] 2> 732547 INFO (zkCallback-945-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (1)
[junit4] 2> 732551 INFO (jetty-closer-934-thread-2) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.cluster, tag=null
[junit4] 2> 732551 INFO (jetty-closer-934-thread-2) [ ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores
[junit4] 2> 732553 INFO (jetty-closer-934-thread-2) [ ] o.a.s.c.Overseer Overseer (id=98756436175945734-127.0.0.1:35647_solr-n_0000000000) closing
[junit4] 2> 732553 INFO (OverseerStateUpdate-98756436175945734-127.0.0.1:35647_solr-n_0000000000) [ ] o.a.s.c.Overseer Overseer Loop exiting : 127.0.0.1:35647_solr
[junit4] 2> 732562 INFO (jetty-closer-934-thread-1) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@381fff36{/solr,null,UNAVAILABLE}
[junit4] 2> 734062 WARN (zkCallback-945-thread-2) [ ] o.a.s.c.c.ZkStateReader ZooKeeper watch triggered, but Solr cannot talk to ZK: [KeeperErrorCode = Session expired for /live_nodes]
[junit4] 2> 734062 ERROR (Thread[Thread-1390,5,TGRP-TestSolrCloudWithDelegationTokens]) [ ] o.a.h.s.t.d.AbstractDelegationTokenSecretManager ExpiredTokenRemover received java.lang.InterruptedException: sleep interrupted
[junit4] 2> 734064 INFO (jetty-closer-934-thread-2) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@2a7070e8{/solr,null,UNAVAILABLE}
[junit4] 2> 734064 ERROR (SUITE-TestSolrCloudWithDelegationTokens-seed#[ABDB6305EAF3FAEB]-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> 734064 INFO (SUITE-TestSolrCloudWithDelegationTokens-seed#[ABDB6305EAF3FAEB]-worker) [ ] o.a.s.c.ZkTestServer connecting to 127.0.0.1:40159 40159
[junit4] 2> 739109 INFO (Thread-1371) [ ] o.a.s.c.ZkTestServer connecting to 127.0.0.1:40159 40159
[junit4] 2> 739109 WARN (Thread-1371) [ ] o.a.s.c.ZkTestServer Watch limit violations:
[junit4] 2> Maximum concurrent create/delete watches above limit:
[junit4] 2>
[junit4] 2> 8 /solr/aliases.json
[junit4] 2> 2 /solr/security.json
[junit4] 2>
[junit4] 2> Maximum concurrent data watches above limit:
[junit4] 2>
[junit4] 2> 8 /solr/clusterprops.json
[junit4] 2> 8 /solr/clusterstate.json
[junit4] 2> 3 /solr/security/zkdtsm/ZKDTSMRoot/ZKDTSMKeyIdRoot
[junit4] 2> 2 /solr/security/zkdtsm/ZKDTSMRoot/ZKDTSMTokensRoot/DT_7
[junit4] 2> 2 /solr/security/zkdtsm/ZKDTSMRoot/ZKDTSMTokensRoot/DT_6
[junit4] 2> 2 /solr/security/zkdtsm/ZKDTSMRoot/ZKDTSMTokensRoot/DT_8
[junit4] 2> 2 /solr/security/zkdtsm/ZKDTSMRoot/ZKDTSMMasterKeyRoot/DK_1
[junit4] 2> 2 /solr/security/zkdtsm/ZKDTSMRoot/ZKDTSMTokensRoot/DT_1
[junit4] 2> 2 /solr/security/zkdtsm/ZKDTSMRoot/ZKDTSMTokensRoot/DT_3
[junit4] 2> 2 /solr/security/zkdtsm/ZKDTSMRoot/ZKDTSMMasterKeyRoot/DK_2
[junit4] 2> 2 /solr/security/zkdtsm/ZKDTSMRoot/ZKDTSMTokensRoot/DT_2
[junit4] 2> 2 /solr/security/zkdtsm/ZKDTSMRoot/ZKDTSMTokensRoot/DT_5
[junit4] 2> 2 /solr/security/zkdtsm/ZKDTSMRoot/ZKDTSMMasterKeyRoot/DK_4
[junit4] 2> 2 /solr/security/zkdtsm/ZKDTSMRoot/ZKDTSMTokensRoot/DT_4
[junit4] 2> 2 /solr/security/zkdtsm/ZKDTSMRoot/ZKDTSMSeqNumRoot
[junit4] 2>
[junit4] 2> Maximum concurrent children watches above limit:
[junit4] 2>
[junit4] 2> 8 /solr/live_nodes
[junit4] 2> 8 /solr/collections
[junit4] 2> 2 /solr/security/zkdtsm/ZKDTSMRoot/ZKDTSMMasterKeyRoot
[junit4] 2> 2 /solr/security/zkdtsm/ZKDTSMRoot/ZKDTSMTokensRoot
[junit4] 2>
[junit4] 2> NOTE: leaving temporary files on disk at: /home/jenkins/workspace/Lucene-Solr-7.0-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.TestSolrCloudWithDelegationTokens_ABDB6305EAF3FAEB-001
[junit4] 2> NOTE: test params are: codec=Asserting(Lucene70): {}, docValues:{}, maxPointsInLeafNode=1353, maxMBSortInHeap=7.279978672725899, sim=RandomSimilarity(queryNorm=false): {}, locale=fr-YT, timezone=Asia/Urumqi
[junit4] 2> NOTE: Linux 4.10.0-33-generic amd64/Oracle Corporation 9 (64-bit)/cpus=8,threads=1,free=131250520,total=518979584
[junit4] 2> NOTE: All tests run in this JVM: [URLClassifyProcessorTest, MetricUtilsTest, TestZkChroot, CircularListTest, CdcrVersionReplicationTest, AnalyticsMergeStrategyTest, CoreAdminCreateDiscoverTest, SolrJmxReporterCloudTest, TestReversedWildcardFilterFactory, RequestLoggingTest, XsltUpdateRequestHandlerTest, TestStressReorder, AtomicUpdatesTest, HLLSerializationTest, DistributedFacetExistsSmallTest, UnloadDistributedZkTest, TestTlogReplica, TestCodecSupport, LeaderElectionTest, MultiTermTest, TestClusterProperties, GraphQueryTest, DocumentBuilderTest, TestComplexPhraseLeadingWildcard, HdfsLockFactoryTest, TestJsonFacetRefinement, UniqFieldsUpdateProcessorFactoryTest, HdfsDirectoryFactoryTest, TestInPlaceUpdatesDistrib, MoveReplicaTest, TestMaxScoreQueryParser, AddBlockUpdateTest, DirectUpdateHandlerTest, DirectUpdateHandlerOptimizeTest, TestSegmentSorting, TestScoreJoinQPNoScore, VersionInfoTest, TestAnalyzeInfixSuggestions, DataDrivenBlockJoinTest, CoreSorterTest, TestDeleteCollectionOnDownNodes, BooleanFieldTest, TestGroupingSearch, TestHalfAndHalfDocValues, TestPayloadScoreQParserPlugin, RecoveryZkTest, ActionThrottleTest, TestUtils, TestSha256AuthenticationProvider, CopyFieldTest, TestMaxTokenLenTokenizer, HdfsBasicDistributedZkTest, TestReqParamsAPI, RegexBoostProcessorTest, SolrCloudReportersTest, RuleEngineTest, TestGeoJSONResponseWriter, HdfsCollectionsAPIDistributedZkTest, TestQueryUtils, BitVectorTest, TestDynamicLoading, FullSolrCloudDistribCmdsTest, QueryEqualityTest, ZkStateReaderTest, TestSurroundQueryParser, ClusterStateTest, TestDynamicFieldResource, SignatureUpdateProcessorFactoryTest, TestAnalyzedSuggestions, HdfsThreadLeakTest, HdfsWriteToMultipleCollectionsTest, SortSpecParsingTest, TestPseudoReturnFields, CdcrReplicationDistributedZkTest, BlockJoinFacetDistribTest, TestSlowCompositeReaderWrapper, PrimitiveFieldTypeTest, ConfigSetsAPITest, TestFreeTextSuggestions, RestartWhileUpdatingTest, TestSolrCloudWithDelegationTokens]
[junit4] Completed [270/730 (1!)] on J2 in 7.27s, 8 tests, 1 failure, 1 skipped <<< FAILURES!
[...truncated 38242 lines...]