Build: https://jenkins.thetaphi.de/job/Lucene-Solr-master-Linux/21867/ Java: 64bit/jdk-9.0.4 -XX:+UseCompressedOops -XX:+UseParallelGC
1 tests failed. FAILED: org.apache.solr.cloud.OverseerRolesTest.testOverseerRole Error Message: Timed out waiting for overseer state change Stack Trace: java.lang.AssertionError: Timed out waiting for overseer state change at __randomizedtesting.SeedInfo.seed([62B57CDAA5A2397:E7E0AA5991E91546]:0) at org.junit.Assert.fail(Assert.java:93) at org.apache.solr.cloud.OverseerRolesTest.waitForNewOverseer(OverseerRolesTest.java:63) at org.apache.solr.cloud.OverseerRolesTest.testOverseerRole(OverseerRolesTest.java:141) at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.base/java.lang.reflect.Method.invoke(Method.java:564) at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1737) at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:934) at com.carrotsearch.randomizedtesting.RandomizedRunner$9.evaluate(RandomizedRunner.java:970) at com.carrotsearch.randomizedtesting.RandomizedRunner$10.evaluate(RandomizedRunner.java:984) at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57) at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:49) at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45) at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:48) at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64) at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47) at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368) at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:817) at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:468) at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:943) at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:829) at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:879) at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:890) at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57) at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45) at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:41) at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40) at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40) at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:53) at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47) at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64) at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:54) at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368) at java.base/java.lang.Thread.run(Thread.java:844) Build Log: [...truncated 13839 lines...] [junit4] Suite: org.apache.solr.cloud.OverseerRolesTest [junit4] 2> 1572891 INFO (SUITE-OverseerRolesTest-seed#[62B57CDAA5A2397]-worker) [ ] o.a.s.SolrTestCaseJ4 SecureRandom sanity checks: test.solr.allowed.securerandom=null & java.security.egd=file:/dev/./urandom [junit4] 2> Creating dataDir: /home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.OverseerRolesTest_62B57CDAA5A2397-001/init-core-data-001 [junit4] 2> 1572891 INFO (SUITE-OverseerRolesTest-seed#[62B57CDAA5A2397]-worker) [ ] o.a.s.SolrTestCaseJ4 Using PointFields (NUMERIC_POINTS_SYSPROP=true) w/NUMERIC_DOCVALUES_SYSPROP=false [junit4] 2> 1572892 INFO (SUITE-OverseerRolesTest-seed#[62B57CDAA5A2397]-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> 1572901 INFO (SUITE-OverseerRolesTest-seed#[62B57CDAA5A2397]-worker) [ ] o.a.s.c.MiniSolrCloudCluster Starting cluster of 4 servers in /home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.OverseerRolesTest_62B57CDAA5A2397-001/tempDir-001 [junit4] 2> 1572901 INFO (SUITE-OverseerRolesTest-seed#[62B57CDAA5A2397]-worker) [ ] o.a.s.c.ZkTestServer STARTING ZK TEST SERVER [junit4] 2> 1572906 INFO (Thread-6002) [ ] o.a.s.c.ZkTestServer client port:0.0.0.0/0.0.0.0:0 [junit4] 2> 1572906 INFO (Thread-6002) [ ] o.a.s.c.ZkTestServer Starting server [junit4] 2> 1572910 ERROR (Thread-6002) [ ] 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> 1573006 INFO (SUITE-OverseerRolesTest-seed#[62B57CDAA5A2397]-worker) [ ] o.a.s.c.ZkTestServer start zk server on port:43301 [junit4] 2> 1573007 INFO (zkConnectionManagerCallback-4738-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected [junit4] 2> 1573010 INFO (jetty-launcher-4735-thread-1) [ ] o.e.j.s.Server jetty-9.4.8.v20171121, build timestamp: 2017-11-21T15:27:37-06:00, git hash: 82b8fb23f757335bb3329d540ce37a2a2615f0a8 [junit4] 2> 1573010 INFO (jetty-launcher-4735-thread-3) [ ] o.e.j.s.Server jetty-9.4.8.v20171121, build timestamp: 2017-11-21T15:27:37-06:00, git hash: 82b8fb23f757335bb3329d540ce37a2a2615f0a8 [junit4] 2> 1573010 INFO (jetty-launcher-4735-thread-2) [ ] o.e.j.s.Server jetty-9.4.8.v20171121, build timestamp: 2017-11-21T15:27:37-06:00, git hash: 82b8fb23f757335bb3329d540ce37a2a2615f0a8 [junit4] 2> 1573010 INFO (jetty-launcher-4735-thread-4) [ ] o.e.j.s.Server jetty-9.4.8.v20171121, build timestamp: 2017-11-21T15:27:37-06:00, git hash: 82b8fb23f757335bb3329d540ce37a2a2615f0a8 [junit4] 2> 1573046 INFO (jetty-launcher-4735-thread-1) [ ] o.e.j.s.session DefaultSessionIdManager workerName=node0 [junit4] 2> 1573046 INFO (jetty-launcher-4735-thread-1) [ ] o.e.j.s.session No SessionScavenger set, using defaults [junit4] 2> 1573046 INFO (jetty-launcher-4735-thread-1) [ ] o.e.j.s.session Scavenging every 600000ms [junit4] 2> 1573051 INFO (jetty-launcher-4735-thread-1) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@3385ec9d{/solr,null,AVAILABLE} [junit4] 2> 1573056 INFO (jetty-launcher-4735-thread-1) [ ] o.e.j.s.AbstractConnector Started ServerConnector@47dc6604{SSL,[ssl, http/1.1]}{127.0.0.1:37819} [junit4] 2> 1573056 INFO (jetty-launcher-4735-thread-1) [ ] o.e.j.s.Server Started @1573104ms [junit4] 2> 1573056 INFO (jetty-launcher-4735-thread-1) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=37819} [junit4] 2> 1573057 ERROR (jetty-launcher-4735-thread-1) [ ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete. [junit4] 2> 1573057 INFO (jetty-launcher-4735-thread-1) [ ] o.a.s.s.SolrDispatchFilter Using logger factory org.apache.logging.slf4j.Log4jLoggerFactory [junit4] 2> 1573057 INFO (jetty-launcher-4735-thread-1) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr™ version 8.0.0 [junit4] 2> 1573057 INFO (jetty-launcher-4735-thread-1) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null [junit4] 2> 1573057 INFO (jetty-launcher-4735-thread-1) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null [junit4] 2> 1573057 INFO (jetty-launcher-4735-thread-1) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2018-04-20T09:22:45.036291Z [junit4] 2> 1573058 INFO (zkConnectionManagerCallback-4740-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected [junit4] 2> 1573058 INFO (jetty-launcher-4735-thread-3) [ ] o.e.j.s.session DefaultSessionIdManager workerName=node0 [junit4] 2> 1573058 INFO (jetty-launcher-4735-thread-3) [ ] o.e.j.s.session No SessionScavenger set, using defaults [junit4] 2> 1573058 INFO (jetty-launcher-4735-thread-3) [ ] o.e.j.s.session Scavenging every 600000ms [junit4] 2> 1573059 INFO (jetty-launcher-4735-thread-1) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading... [junit4] 2> 1573062 INFO (jetty-launcher-4735-thread-2) [ ] o.e.j.s.session DefaultSessionIdManager workerName=node0 [junit4] 2> 1573062 INFO (jetty-launcher-4735-thread-2) [ ] o.e.j.s.session No SessionScavenger set, using defaults [junit4] 2> 1573062 INFO (jetty-launcher-4735-thread-2) [ ] o.e.j.s.session Scavenging every 600000ms [junit4] 2> 1573066 INFO (jetty-launcher-4735-thread-4) [ ] o.e.j.s.session DefaultSessionIdManager workerName=node0 [junit4] 2> 1573066 INFO (jetty-launcher-4735-thread-4) [ ] o.e.j.s.session No SessionScavenger set, using defaults [junit4] 2> 1573066 INFO (jetty-launcher-4735-thread-4) [ ] o.e.j.s.session Scavenging every 600000ms [junit4] 2> 1573066 INFO (jetty-launcher-4735-thread-2) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@7fe790f1{/solr,null,AVAILABLE} [junit4] 2> 1573066 INFO (jetty-launcher-4735-thread-3) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@110e59a2{/solr,null,AVAILABLE} [junit4] 2> 1573066 INFO (jetty-launcher-4735-thread-4) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@268ef0da{/solr,null,AVAILABLE} [junit4] 2> 1573066 INFO (jetty-launcher-4735-thread-2) [ ] o.e.j.s.AbstractConnector Started ServerConnector@66215a4f{SSL,[ssl, http/1.1]}{127.0.0.1:36427} [junit4] 2> 1573066 INFO (jetty-launcher-4735-thread-4) [ ] o.e.j.s.AbstractConnector Started ServerConnector@6901d706{SSL,[ssl, http/1.1]}{127.0.0.1:35239} [junit4] 2> 1573066 INFO (jetty-launcher-4735-thread-2) [ ] o.e.j.s.Server Started @1573113ms [junit4] 2> 1573066 INFO (jetty-launcher-4735-thread-2) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=36427} [junit4] 2> 1573067 ERROR (jetty-launcher-4735-thread-2) [ ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete. [junit4] 2> 1573067 INFO (jetty-launcher-4735-thread-2) [ ] o.a.s.s.SolrDispatchFilter Using logger factory org.apache.logging.slf4j.Log4jLoggerFactory [junit4] 2> 1573067 INFO (jetty-launcher-4735-thread-2) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr™ version 8.0.0 [junit4] 2> 1573067 INFO (jetty-launcher-4735-thread-2) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null [junit4] 2> 1573067 INFO (jetty-launcher-4735-thread-2) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null [junit4] 2> 1573067 INFO (jetty-launcher-4735-thread-2) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2018-04-20T09:22:45.046145Z [junit4] 2> 1573066 INFO (jetty-launcher-4735-thread-3) [ ] o.e.j.s.AbstractConnector Started ServerConnector@1a45cbc1{SSL,[ssl, http/1.1]}{127.0.0.1:34905} [junit4] 2> 1573066 INFO (jetty-launcher-4735-thread-4) [ ] o.e.j.s.Server Started @1573113ms [junit4] 2> 1573067 INFO (jetty-launcher-4735-thread-3) [ ] o.e.j.s.Server Started @1573114ms [junit4] 2> 1573067 INFO (jetty-launcher-4735-thread-4) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=35239} [junit4] 2> 1573067 INFO (jetty-launcher-4735-thread-3) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=34905} [junit4] 2> 1573067 ERROR (jetty-launcher-4735-thread-3) [ ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete. [junit4] 2> 1573067 INFO (jetty-launcher-4735-thread-3) [ ] o.a.s.s.SolrDispatchFilter Using logger factory org.apache.logging.slf4j.Log4jLoggerFactory [junit4] 2> 1573067 ERROR (jetty-launcher-4735-thread-4) [ ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete. [junit4] 2> 1573067 INFO (jetty-launcher-4735-thread-4) [ ] o.a.s.s.SolrDispatchFilter Using logger factory org.apache.logging.slf4j.Log4jLoggerFactory [junit4] 2> 1573067 INFO (jetty-launcher-4735-thread-3) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr™ version 8.0.0 [junit4] 2> 1573067 INFO (jetty-launcher-4735-thread-3) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null [junit4] 2> 1573067 INFO (jetty-launcher-4735-thread-4) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr™ version 8.0.0 [junit4] 2> 1573067 INFO (jetty-launcher-4735-thread-3) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null [junit4] 2> 1573067 INFO (jetty-launcher-4735-thread-3) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2018-04-20T09:22:45.046755Z [junit4] 2> 1573067 INFO (jetty-launcher-4735-thread-4) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null [junit4] 2> 1573067 INFO (jetty-launcher-4735-thread-4) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null [junit4] 2> 1573067 INFO (jetty-launcher-4735-thread-4) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2018-04-20T09:22:45.046803Z [junit4] 2> 1573079 INFO (jetty-launcher-4735-thread-1) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:43301/solr [junit4] 2> 1573087 INFO (zkConnectionManagerCallback-4742-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected [junit4] 2> 1573087 INFO (jetty-launcher-4735-thread-2) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading... [junit4] 2> 1573107 INFO (zkConnectionManagerCallback-4745-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected [junit4] 2> 1573107 INFO (jetty-launcher-4735-thread-3) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading... [junit4] 2> 1573110 INFO (zkConnectionManagerCallback-4747-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected [junit4] 2> 1573110 INFO (zkConnectionManagerCallback-4750-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected [junit4] 2> 1573110 INFO (jetty-launcher-4735-thread-4) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading... [junit4] 2> 1573115 INFO (jetty-launcher-4735-thread-2) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:43301/solr [junit4] 2> 1573122 INFO (jetty-launcher-4735-thread-3) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:43301/solr [junit4] 2> 1573123 INFO (jetty-launcher-4735-thread-4) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:43301/solr [junit4] 2> 1573126 INFO (zkConnectionManagerCallback-4756-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected [junit4] 2> 1573150 INFO (zkConnectionManagerCallback-4754-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected [junit4] 2> 1573154 INFO (zkConnectionManagerCallback-4761-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected [junit4] 2> 1573158 INFO (zkConnectionManagerCallback-4764-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected [junit4] 2> 1573166 INFO (jetty-launcher-4735-thread-1) [n:127.0.0.1:37819_solr ] o.a.s.c.Overseer Overseer (id=null) closing [junit4] 2> 1573166 INFO (jetty-launcher-4735-thread-1) [n:127.0.0.1:37819_solr ] o.a.s.c.OverseerElectionContext I am going to be the leader 127.0.0.1:37819_solr [junit4] 2> 1573166 INFO (jetty-launcher-4735-thread-1) [n:127.0.0.1:37819_solr ] o.a.s.c.Overseer Overseer (id=72171219722829830-127.0.0.1:37819_solr-n_0000000000) starting [junit4] 2> 1573174 INFO (zkConnectionManagerCallback-4768-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected [junit4] 2> 1573177 INFO (jetty-launcher-4735-thread-2) [n:127.0.0.1:36427_solr ] o.a.s.c.Overseer Overseer (id=null) closing [junit4] 2> 1573178 INFO (jetty-launcher-4735-thread-2) [n:127.0.0.1:36427_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:36427_solr [junit4] 2> 1573194 INFO (zkCallback-4755-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1) [junit4] 2> 1573194 INFO (zkConnectionManagerCallback-4770-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected [junit4] 2> 1573196 INFO (jetty-launcher-4735-thread-4) [n:127.0.0.1:35239_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1) [junit4] 2> 1573197 INFO (jetty-launcher-4735-thread-4) [n:127.0.0.1:35239_solr ] o.a.s.c.Overseer Overseer (id=null) closing [junit4] 2> 1573198 INFO (jetty-launcher-4735-thread-4) [n:127.0.0.1:35239_solr ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores [junit4] 2> 1573198 INFO (jetty-launcher-4735-thread-4) [n:127.0.0.1:35239_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:35239_solr [junit4] 2> 1573202 INFO (zkCallback-4767-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1) [junit4] 2> 1573203 INFO (zkCallback-4755-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2) [junit4] 2> 1573214 INFO (zkCallback-4769-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2) [junit4] 2> 1573218 INFO (zkConnectionManagerCallback-4779-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected [junit4] 2> 1573218 INFO (zkConnectionManagerCallback-4772-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected [junit4] 2> 1573219 INFO (zkCallback-4767-thread-2) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2) [junit4] 2> 1573219 INFO (jetty-launcher-4735-thread-1) [n:127.0.0.1:37819_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (2) [junit4] 2> 1573219 INFO (jetty-launcher-4735-thread-1) [n:127.0.0.1:37819_solr ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:43301/solr ready [junit4] 2> 1573222 INFO (jetty-launcher-4735-thread-3) [n:127.0.0.1:34905_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (2) [junit4] 2> 1573223 INFO (jetty-launcher-4735-thread-3) [n:127.0.0.1:34905_solr ] o.a.s.c.Overseer Overseer (id=null) closing [junit4] 2> 1573224 INFO (jetty-launcher-4735-thread-3) [n:127.0.0.1:34905_solr ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores [junit4] 2> 1573224 INFO (jetty-launcher-4735-thread-3) [n:127.0.0.1:34905_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:34905_solr [junit4] 2> 1573224 INFO (zkCallback-4755-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3) [junit4] 2> 1573263 INFO (zkCallback-4769-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3) [junit4] 2> 1573263 INFO (jetty-launcher-4735-thread-1) [n:127.0.0.1:37819_solr ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores [junit4] 2> 1573263 INFO (jetty-launcher-4735-thread-1) [n:127.0.0.1:37819_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:37819_solr [junit4] 2> 1573264 INFO (zkCallback-4769-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4) [junit4] 2> 1573290 INFO (zkCallback-4771-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (4) [junit4] 2> 1573290 INFO (zkCallback-4767-thread-2) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (4) [junit4] 2> 1573290 INFO (zkCallback-4755-thread-2) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4) [junit4] 2> 1573314 INFO (zkCallback-4778-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (4) [junit4] 2> 1573432 INFO (jetty-launcher-4735-thread-2) [n:127.0.0.1:36427_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_36427.solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@4cd0be5f [junit4] 2> 1573440 INFO (jetty-launcher-4735-thread-2) [n:127.0.0.1:36427_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_36427.solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@4cd0be5f [junit4] 2> 1573440 INFO (jetty-launcher-4735-thread-2) [n:127.0.0.1:36427_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_36427.solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@4cd0be5f [junit4] 2> 1573445 INFO (jetty-launcher-4735-thread-4) [n:127.0.0.1:35239_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_35239.solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@4cd0be5f [junit4] 2> 1573446 INFO (jetty-launcher-4735-thread-2) [n:127.0.0.1:36427_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.OverseerRolesTest_62B57CDAA5A2397-001/tempDir-001/node2/. [junit4] 2> 1573454 INFO (jetty-launcher-4735-thread-4) [n:127.0.0.1:35239_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_35239.solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@4cd0be5f [junit4] 2> 1573454 INFO (jetty-launcher-4735-thread-4) [n:127.0.0.1:35239_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_35239.solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@4cd0be5f [junit4] 2> 1573455 INFO (jetty-launcher-4735-thread-4) [n:127.0.0.1:35239_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.OverseerRolesTest_62B57CDAA5A2397-001/tempDir-001/node4/. [junit4] 2> 1573498 INFO (zkConnectionManagerCallback-4788-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected [junit4] 2> 1573499 INFO (jetty-launcher-4735-thread-1) [n:127.0.0.1:37819_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_37819.solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@4cd0be5f [junit4] 2> 1573499 INFO (jetty-launcher-4735-thread-2) [n:127.0.0.1:36427_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (4) [junit4] 2> 1573499 INFO (jetty-launcher-4735-thread-2) [n:127.0.0.1:36427_solr ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:43301/solr ready [junit4] 2> 1573519 INFO (zkConnectionManagerCallback-4793-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected [junit4] 2> 1573519 INFO (jetty-launcher-4735-thread-4) [n:127.0.0.1:35239_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (4) [junit4] 2> 1573520 INFO (jetty-launcher-4735-thread-4) [n:127.0.0.1:35239_solr ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:43301/solr ready [junit4] 2> 1573536 INFO (jetty-launcher-4735-thread-1) [n:127.0.0.1:37819_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_37819.solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@4cd0be5f [junit4] 2> 1573536 INFO (jetty-launcher-4735-thread-1) [n:127.0.0.1:37819_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_37819.solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@4cd0be5f [junit4] 2> 1573537 INFO (jetty-launcher-4735-thread-1) [n:127.0.0.1:37819_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.OverseerRolesTest_62B57CDAA5A2397-001/tempDir-001/node1/. [junit4] 2> 1573667 INFO (jetty-launcher-4735-thread-3) [n:127.0.0.1:34905_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_34905.solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@4cd0be5f [junit4] 2> 1573672 INFO (jetty-launcher-4735-thread-3) [n:127.0.0.1:34905_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_34905.solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@4cd0be5f [junit4] 2> 1573672 INFO (jetty-launcher-4735-thread-3) [n:127.0.0.1:34905_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_34905.solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@4cd0be5f [junit4] 2> 1573673 INFO (jetty-launcher-4735-thread-3) [n:127.0.0.1:34905_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.OverseerRolesTest_62B57CDAA5A2397-001/tempDir-001/node3/. [junit4] 2> 1573681 INFO (zkConnectionManagerCallback-4798-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected [junit4] 2> 1573682 INFO (jetty-launcher-4735-thread-3) [n:127.0.0.1:34905_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (4) [junit4] 2> 1573682 INFO (jetty-launcher-4735-thread-3) [n:127.0.0.1:34905_solr ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:43301/solr ready [junit4] 2> 1573713 INFO (zkConnectionManagerCallback-4800-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected [junit4] 2> 1573719 INFO (zkConnectionManagerCallback-4805-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected [junit4] 2> 1573740 INFO (SUITE-OverseerRolesTest-seed#[62B57CDAA5A2397]-worker) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (4) [junit4] 2> 1573741 INFO (SUITE-OverseerRolesTest-seed#[62B57CDAA5A2397]-worker) [ ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:43301/solr ready [junit4] 2> 1573755 INFO (TEST-OverseerRolesTest.testOverseerRole-seed#[62B57CDAA5A2397]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testOverseerRole [junit4] 2> 1573755 INFO (TEST-OverseerRolesTest.testOverseerRole-seed#[62B57CDAA5A2397]) [ ] o.a.s.c.OverseerRolesTest Overseer: 127.0.0.1:37819_solr [junit4] 2> 1573755 INFO (TEST-OverseerRolesTest.testOverseerRole-seed#[62B57CDAA5A2397]) [ ] o.a.s.c.OverseerRolesTest Election queue: [junit4] 2> 1573755 INFO (TEST-OverseerRolesTest.testOverseerRole-seed#[62B57CDAA5A2397]) [ ] o.a.s.c.OverseerRolesTest ### Setting overseer designate 127.0.0.1:36427_solr [junit4] 2> 1573768 INFO (qtp1921274689-19370) [n:127.0.0.1:36427_solr ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :addrole with params node=127.0.0.1:36427_solr&role=overseer&action=ADDROLE&wt=javabin&version=2 and sendToOCPQueue=true [junit4] 2> 1573769 INFO (OverseerThreadFactory-7211-thread-1) [ ] o.a.s.c.a.c.OverseerRoleCmd Overseer role added to 127.0.0.1:36427_solr [junit4] 2> 1573771 INFO (Thread-6039) [ ] o.a.s.c.OverseerNodePrioritizer prioritizing overseer nodes at 72171219722829830-127.0.0.1:37819_solr-n_0000000000 overseer designates are [127.0.0.1:36427_solr] [junit4] 2> 1573771 INFO (qtp1921274689-19370) [n:127.0.0.1:36427_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={node=127.0.0.1:36427_solr&role=overseer&action=ADDROLE&wt=javabin&version=2} status=0 QTime=3 [junit4] 2> 1573771 INFO (Thread-6039) [ ] o.a.s.c.OverseerNodePrioritizer sorted nodes [72171219722829830-127.0.0.1:37819_solr-n_0000000000, 72171219722829834-127.0.0.1:36427_solr-n_0000000001, 72171219722829835-127.0.0.1:35239_solr-n_0000000002, 72171219722829836-127.0.0.1:34905_solr-n_0000000003] [junit4] 2> 1573772 INFO (OverseerStateUpdate-72171219722829830-127.0.0.1:37819_solr-n_0000000000) [ ] o.a.s.c.Overseer Quit command received { [junit4] 2> "operation":"quit", [junit4] 2> "id":"72171219722829830-127.0.0.1:37819_solr-n_0000000000"} 127.0.0.1:37819_solr [junit4] 2> 1573773 INFO (OverseerStateUpdate-72171219722829830-127.0.0.1:37819_solr-n_0000000000) [ ] o.a.s.c.Overseer Overseer Loop exiting : 127.0.0.1:37819_solr [junit4] 2> 1573774 WARN (OverseerExitThread) [ ] o.a.s.c.Overseer I'm exiting, but I'm still the leader [junit4] 2> 1573775 INFO (OverseerExitThread) [ ] o.a.s.c.Overseer Overseer (id=72171219722829830-127.0.0.1:37819_solr-n_0000000000) closing [junit4] 2> 1573775 WARN (OverseerAutoScalingTriggerThread-72171219722829830-127.0.0.1:37819_solr-n_0000000000) [ ] o.a.s.c.a.OverseerTriggerThread OverseerTriggerThread woken up but we are closed, exiting. [junit4] 2> 1573776 INFO (zkCallback-4767-thread-2) [ ] o.a.s.c.OverseerElectionContext I am going to be the leader 127.0.0.1:36427_solr [junit4] 2> 1573776 INFO (zkCallback-4767-thread-2) [ ] o.a.s.c.Overseer Overseer (id=72171219722829834-127.0.0.1:36427_solr-n_0000000001) starting [junit4] 2> 1573872 INFO (TEST-OverseerRolesTest.testOverseerRole-seed#[62B57CDAA5A2397]) [ ] o.a.s.c.OverseerRolesTest ### Adding another overseer designate 127.0.0.1:34905_solr [junit4] 2> 1573873 INFO (qtp1921274689-19375) [n:127.0.0.1:36427_solr ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :addrole with params node=127.0.0.1:34905_solr&role=overseer&action=ADDROLE&wt=javabin&version=2 and sendToOCPQueue=true [junit4] 2> 1573874 INFO (OverseerThreadFactory-7223-thread-1) [ ] o.a.s.c.a.c.OverseerRoleCmd Overseer role added to 127.0.0.1:34905_solr [junit4] 2> 1573875 INFO (qtp1921274689-19375) [n:127.0.0.1:36427_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={node=127.0.0.1:34905_solr&role=overseer&action=ADDROLE&wt=javabin&version=2} status=0 QTime=2 [junit4] 2> 1573876 INFO (TEST-OverseerRolesTest.testOverseerRole-seed#[62B57CDAA5A2397]) [ ] o.a.s.c.OverseerRolesTest Overseer: 127.0.0.1:36427_solr [junit4] 2> 1573876 INFO (TEST-OverseerRolesTest.testOverseerRole-seed#[62B57CDAA5A2397]) [ ] o.a.s.c.OverseerRolesTest Election queue: [junit4] 2> 1573876 INFO (TEST-OverseerRolesTest.testOverseerRole-seed#[62B57CDAA5A2397]) [ ] o.a.s.c.ChaosMonkey monkey: stop jetty! 36427 [junit4] 2> 1573876 INFO (TEST-OverseerRolesTest.testOverseerRole-seed#[62B57CDAA5A2397]) [ ] o.a.s.c.CoreContainer Shutting down CoreContainer instance=497883012 [junit4] 2> 1573876 INFO (TEST-OverseerRolesTest.testOverseerRole-seed#[62B57CDAA5A2397]) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.node, tag=null [junit4] 2> 1573876 INFO (TEST-OverseerRolesTest.testOverseerRole-seed#[62B57CDAA5A2397]) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@35fb9fdc: rootName = solr_36427, domain = solr.node, service url = null, agent id = null] for registry solr.node / com.codahale.metrics.MetricRegistry@58aaade1 [junit4] 2> 1573879 INFO (TEST-OverseerRolesTest.testOverseerRole-seed#[62B57CDAA5A2397]) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jvm, tag=null [junit4] 2> 1573879 INFO (TEST-OverseerRolesTest.testOverseerRole-seed#[62B57CDAA5A2397]) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@51a444c5: rootName = solr_36427, domain = solr.jvm, service url = null, agent id = null] for registry solr.jvm / com.codahale.metrics.MetricRegistry@940aa8f [junit4] 2> 1573882 INFO (TEST-OverseerRolesTest.testOverseerRole-seed#[62B57CDAA5A2397]) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jetty, tag=null [junit4] 2> 1573882 INFO (TEST-OverseerRolesTest.testOverseerRole-seed#[62B57CDAA5A2397]) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@5096528b: rootName = solr_36427, domain = solr.jetty, service url = null, agent id = null] for registry solr.jetty / com.codahale.metrics.MetricRegistry@cbf85f5 [junit4] 2> 1573883 INFO (TEST-OverseerRolesTest.testOverseerRole-seed#[62B57CDAA5A2397]) [ ] o.a.s.c.ZkController Remove node as live in ZooKeeper:/live_nodes/127.0.0.1:36427_solr [junit4] 2> 1573883 INFO (zkCallback-4771-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (4) -> (3) [junit4] 2> 1573884 INFO (zkCallback-4767-thread-2) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (4) -> (3) [junit4] 2> 1573884 INFO (zkCallback-4755-thread-2) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (4) -> (3) [junit4] 2> 1573884 INFO (zkCallback-4778-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (4) -> (3) [junit4] 2> 1573884 INFO (zkCallback-4769-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (4) -> (3) [junit4] 2> 1573884 INFO (TEST-OverseerRolesTest.testOverseerRole-seed#[62B57CDAA5A2397]) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.cluster, tag=null [junit4] 2> 1573884 INFO (TEST-OverseerRolesTest.testOverseerRole-seed#[62B57CDAA5A2397]) [ ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores [junit4] 2> 1573885 INFO (TEST-OverseerRolesTest.testOverseerRole-seed#[62B57CDAA5A2397]) [ ] o.a.s.c.Overseer Overseer (id=72171219722829834-127.0.0.1:36427_solr-n_0000000001) closing [junit4] 2> 1573885 INFO (zkCallback-4792-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (4) -> (3) [junit4] 2> 1573885 INFO (zkCallback-4804-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (4) -> (3) [junit4] 2> 1573885 INFO (OverseerStateUpdate-72171219722829834-127.0.0.1:36427_solr-n_0000000001) [ ] o.a.s.c.Overseer Overseer Loop exiting : 127.0.0.1:36427_solr [junit4] 2> 1573885 INFO (zkCallback-4787-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (4) -> (3) [junit4] 2> 1573885 INFO (zkCallback-4797-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (4) -> (3) [junit4] 2> 1573886 WARN (OverseerAutoScalingTriggerThread-72171219722829834-127.0.0.1:36427_solr-n_0000000001) [ ] o.a.s.c.a.OverseerTriggerThread OverseerTriggerThread woken up but we are closed, exiting. [junit4] 2> 1573887 INFO (zkCallback-4769-thread-1) [ ] o.a.s.c.OverseerElectionContext I am going to be the leader 127.0.0.1:35239_solr [junit4] 2> 1573888 INFO (zkCallback-4769-thread-1) [ ] o.a.s.c.Overseer Overseer (id=72171219722829835-127.0.0.1:35239_solr-n_0000000002) starting [junit4] 2> 1573888 INFO (TEST-OverseerRolesTest.testOverseerRole-seed#[62B57CDAA5A2397]) [ ] o.e.j.s.AbstractConnector Stopped ServerConnector@66215a4f{SSL,[ssl, http/1.1]}{127.0.0.1:0} [junit4] 2> 1573888 INFO (TEST-OverseerRolesTest.testOverseerRole-seed#[62B57CDAA5A2397]) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@7fe790f1{/solr,null,UNAVAILABLE} [junit4] 2> 1573888 INFO (TEST-OverseerRolesTest.testOverseerRole-seed#[62B57CDAA5A2397]) [ ] o.e.j.s.session Stopped scavenging [junit4] 2> 1573890 INFO (OverseerCollectionConfigSetProcessor-72171219722829835-127.0.0.1:35239_solr-n_0000000002) [ ] o.a.s.c.OverseerNodePrioritizer prioritizing overseer nodes at 72171219722829835-127.0.0.1:35239_solr-n_0000000002 overseer designates are [127.0.0.1:36427_solr, 127.0.0.1:34905_solr] [junit4] 2> 1573890 INFO (OverseerCollectionConfigSetProcessor-72171219722829835-127.0.0.1:35239_solr-n_0000000002) [ ] o.a.s.c.OverseerNodePrioritizer sorted nodes [72171219722829835-127.0.0.1:35239_solr-n_0000000002, 72171219722829836-127.0.0.1:34905_solr-n_0000000003, 72171219722829830-127.0.0.1:37819_solr-n_0000000004] [junit4] 2> 1573891 INFO (OverseerStateUpdate-72171219722829835-127.0.0.1:35239_solr-n_0000000002) [ ] o.a.s.c.Overseer Quit command received { [junit4] 2> "operation":"quit", [junit4] 2> "id":"72171219722829835-127.0.0.1:35239_solr-n_0000000002"} 127.0.0.1:35239_solr [junit4] 2> 1573892 INFO (OverseerStateUpdate-72171219722829835-127.0.0.1:35239_solr-n_0000000002) [ ] o.a.s.c.Overseer Overseer Loop exiting : 127.0.0.1:35239_solr [junit4] 2> 1573892 WARN (OverseerExitThread) [ ] o.a.s.c.Overseer I'm exiting, but I'm still the leader [junit4] 2> 1573892 INFO (OverseerExitThread) [ ] o.a.s.c.Overseer Overseer (id=72171219722829835-127.0.0.1:35239_solr-n_0000000002) closing [junit4] 2> 1573892 WARN (OverseerAutoScalingTriggerThread-72171219722829835-127.0.0.1:35239_solr-n_0000000002) [ ] o.a.s.c.a.OverseerTriggerThread OverseerTriggerThread woken up but we are closed, exiting. [junit4] 2> 1573893 INFO (zkCallback-4771-thread-1) [ ] o.a.s.c.OverseerElectionContext I am going to be the leader 127.0.0.1:34905_solr [junit4] 2> 1573893 INFO (zkCallback-4771-thread-1) [ ] o.a.s.c.Overseer Overseer (id=72171219722829836-127.0.0.1:34905_solr-n_0000000003) starting [junit4] 2> 1573989 INFO (TEST-OverseerRolesTest.testOverseerRole-seed#[62B57CDAA5A2397]) [ ] o.a.s.c.OverseerRolesTest ### Adding last overseer designate 127.0.0.1:35239_solr [junit4] 2> 1574000 INFO (qtp2139899810-19364) [n:127.0.0.1:34905_solr ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :addrole with params node=127.0.0.1:35239_solr&role=overseer&action=ADDROLE&wt=javabin&version=2 and sendToOCPQueue=true [junit4] 2> 1574002 INFO (OverseerThreadFactory-7232-thread-1) [ ] o.a.s.c.a.c.OverseerRoleCmd Overseer role added to 127.0.0.1:35239_solr [junit4] 2> 1574003 INFO (qtp2139899810-19364) [n:127.0.0.1:34905_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={node=127.0.0.1:35239_solr&role=overseer&action=ADDROLE&wt=javabin&version=2} status=0 QTime=3 [junit4] 2> 1574004 INFO (TEST-OverseerRolesTest.testOverseerRole-seed#[62B57CDAA5A2397]) [ ] o.a.s.c.OverseerRolesTest Overseer: 127.0.0.1:34905_solr [junit4] 2> 1574004 INFO (TEST-OverseerRolesTest.testOverseerRole-seed#[62B57CDAA5A2397]) [ ] o.a.s.c.OverseerRolesTest Election queue: [junit4] 2> 1574004 INFO (qtp2139899810-19371) [n:127.0.0.1:34905_solr ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :removerole with params node=127.0.0.1:34905_solr&role=overseer&action=REMOVEROLE&wt=javabin&version=2 and sendToOCPQueue=true [junit4] 2> 1574005 INFO (OverseerCollectionConfigSetProcessor-72171219722829836-127.0.0.1:34905_solr-n_0000000003) [ ] 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> 1574005 INFO (OverseerThreadFactory-7232-thread-2) [ ] o.a.s.c.a.c.OverseerRoleCmd Overseer role removed from 127.0.0.1:34905_solr [junit4] 2> 1574006 INFO (Thread-6043) [ ] o.a.s.c.OverseerNodePrioritizer prioritizing overseer nodes at 72171219722829836-127.0.0.1:34905_solr-n_0000000003 overseer designates are [127.0.0.1:36427_solr, 127.0.0.1:35239_solr] [junit4] 2> 1574006 INFO (Thread-6043) [ ] o.a.s.c.OverseerNodePrioritizer sorted nodes [72171219722829836-127.0.0.1:34905_solr-n_0000000003, 72171219722829830-127.0.0.1:37819_solr-n_0000000004, 72171219722829835-127.0.0.1:35239_solr-n_0000000005] [junit4] 2> 1574006 INFO (Thread-6043) [ ] o.a.s.c.OverseerNodePrioritizer asking node 72171219722829835-127.0.0.1:35239_solr-n_0000000005 to come join election at head [junit4] 2> 1574006 INFO (qtp2139899810-19371) [n:127.0.0.1:34905_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={node=127.0.0.1:34905_solr&role=overseer&action=REMOVEROLE&wt=javabin&version=2} status=0 QTime=1 [junit4] 2> 1574019 INFO (qtp575407296-19366) [n:127.0.0.1:35239_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={op=rejoinAtHead&qt=/admin/cores&action=OVERSEEROP&electionNode=72171219722829835-127.0.0.1:35239_solr-n_0000000005&wt=javabin&version=2} status=0 QTime=0 [junit4] 2> 1574020 INFO (Thread-6043) [ ] o.a.s.c.OverseerNodePrioritizer asking the old first in line 72171219722829830-127.0.0.1:37819_solr-n_0000000004 to rejoin election [junit4] 2> 1574033 INFO (qtp1448263483-19354) [n:127.0.0.1:37819_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={op=rejoin&qt=/admin/cores&action=OVERSEEROP&electionNode=72171219722829830-127.0.0.1:37819_solr-n_0000000004&wt=javabin&version=2} status=0 QTime=0 [junit4] 2> 1574034 INFO (OverseerStateUpdate-72171219722829836-127.0.0.1:34905_solr-n_0000000003) [ ] o.a.s.c.Overseer Quit command received { [junit4] 2> "operation":"quit", [junit4] 2> "id":"72171219722829836-127.0.0.1:34905_solr-n_0000000003"} 127.0.0.1:34905_solr [junit4] 2> 1574034 INFO (OverseerStateUpdate-72171219722829836-127.0.0.1:34905_solr-n_0000000003) [ ] o.a.s.c.Overseer Overseer Loop exiting : 127.0.0.1:34905_solr [junit4] 2> 1574034 WARN (OverseerExitThread) [ ] o.a.s.c.Overseer I'm exiting, but I'm still the leader [junit4] 2> 1574034 INFO (OverseerExitThread) [ ] o.a.s.c.Overseer Overseer (id=72171219722829836-127.0.0.1:34905_solr-n_0000000003) closing [junit4] 2> 1574034 WARN (OverseerAutoScalingTriggerThread-72171219722829836-127.0.0.1:34905_solr-n_0000000003) [ ] o.a.s.c.a.OverseerTriggerThread OverseerTriggerThread woken up but we are closed, exiting. [junit4] 2> 1574035 INFO (zkCallback-4755-thread-2) [ ] o.a.s.c.OverseerElectionContext I am going to be the leader 127.0.0.1:37819_solr [junit4] 2> 1574036 INFO (zkCallback-4755-thread-2) [ ] o.a.s.c.Overseer Overseer (id=72171219722829830-127.0.0.1:37819_solr-n_0000000004) starting [junit4] 2> 1574039 INFO (OverseerCollectionConfigSetProcessor-72171219722829830-127.0.0.1:37819_solr-n_0000000004) [ ] o.a.s.c.OverseerNodePrioritizer prioritizing overseer nodes at 72171219722829830-127.0.0.1:37819_solr-n_0000000004 overseer designates are [127.0.0.1:36427_solr, 127.0.0.1:35239_solr] [junit4] 2> 1574039 INFO (OverseerCollectionConfigSetProcessor-72171219722829830-127.0.0.1:37819_solr-n_0000000004) [ ] o.a.s.c.OverseerNodePrioritizer sorted nodes [72171219722829830-127.0.0.1:37819_solr-n_0000000004, 72171219722829835-127.0.0.1:35239_solr-n_0000000005, 72171219722829836-127.0.0.1:34905_solr-n_0000000006] [junit4] 2> 1574040 INFO (OverseerStateUpdate-72171219722829830-127.0.0.1:37819_solr-n_0000000004) [ ] o.a.s.c.Overseer Quit command received { [junit4] 2> "operation":"quit", [junit4] 2> "id":"72171219722829830-127.0.0.1:37819_solr-n_0000000004"} 127.0.0.1:37819_solr [junit4] 2> 1574040 INFO (OverseerStateUpdate-72171219722829830-127.0.0.1:37819_solr-n_0000000004) [ ] o.a.s.c.Overseer Overseer Loop exiting : 127.0.0.1:37819_solr [junit4] 2> 1574040 WARN (OverseerExitThread) [ ] o.a.s.c.Overseer I'm exiting, but I'm still the leader [junit4] 2> 1574041 INFO (OverseerExitThread) [ ] o.a.s.c.Overseer Overseer (id=72171219722829830-127.0.0.1:37819_solr-n_0000000004) closing [junit4] 2> 1574041 WARN (OverseerAutoScalingTriggerThread-72171219722829830-127.0.0.1:37819_solr-n_0000000004) [ ] o.a.s.c.a.OverseerTriggerThread OverseerTriggerThread woken up but we are closed, exiting. [junit4] 2> 1574042 INFO (zkCallback-4769-thread-1) [ ] o.a.s.c.OverseerElectionContext I am going to be the leader 127.0.0.1:35239_solr [junit4] 2> 1574042 INFO (zkCallback-4769-thread-1) [ ] o.a.s.c.Overseer Overseer (id=72171219722829835-127.0.0.1:35239_solr-n_0000000005) starting [junit4] 2> 1574107 INFO (qtp2139899810-19364) [n:127.0.0.1:34905_solr ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :addrole with params node=127.0.0.1:34905_solr&role=overseer&action=ADDROLE&wt=javabin&version=2 and sendToOCPQueue=true [junit4] 2> 1574109 INFO (OverseerThreadFactory-7240-thread-1) [ ] o.a.s.c.a.c.OverseerRoleCmd Overseer role added to 127.0.0.1:34905_solr [junit4] 2> 1574110 INFO (qtp2139899810-19364) [n:127.0.0.1:34905_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={node=127.0.0.1:34905_solr&role=overseer&action=ADDROLE&wt=javabin&version=2} status=0 QTime=2 [junit4] 2> 1574110 INFO (TEST-OverseerRolesTest.testOverseerRole-seed#[62B57CDAA5A2397]) [ ] o.a.s.c.OverseerRolesTest ### Sending QUIT to overseer 127.0.0.1:35239_solr [junit4] 2> 1574111 INFO (OverseerStateUpdate-72171219722829835-127.0.0.1:35239_solr-n_0000000005) [ ] o.a.s.c.Overseer Quit command received { [junit4] 2> "operation":"quit", [junit4] 2> "id":"72171219722829835-127.0.0.1:35239_solr-n_0000000005"} 127.0.0.1:35239_solr [junit4] 2> 1574111 INFO (OverseerStateUpdate-72171219722829835-127.0.0.1:35239_solr-n_0000000005) [ ] o.a.s.c.Overseer Overseer Loop exiting : 127.0.0.1:35239_solr [junit4] 2> 1574112 WARN (OverseerExitThread) [ ] o.a.s.c.Overseer I'm exiting, but I'm still the leader [junit4] 2> 1574112 INFO (Thread-6044) [ ] o.a.s.c.OverseerNodePrioritizer prioritizing overseer nodes at 72171219722829835-127.0.0.1:35239_solr-n_0000000005 overseer designates are [127.0.0.1:36427_solr, 127.0.0.1:35239_solr, 127.0.0.1:34905_solr] [junit4] 2> 1574113 INFO (zkCallback-4771-thread-1) [ ] o.a.s.c.OverseerElectionContext I am going to be the leader 127.0.0.1:34905_solr [junit4] 2> 1574113 INFO (zkCallback-4771-thread-1) [ ] o.a.s.c.Overseer Overseer (id=72171219722829836-127.0.0.1:34905_solr-n_0000000006) starting [junit4] 2> 1574114 INFO (OverseerExitThread) [ ] o.a.s.c.Overseer Overseer (id=72171219722829835-127.0.0.1:35239_solr-n_0000000005) closing [junit4] 2> 1574114 INFO (Thread-6044) [ ] o.a.s.c.OverseerNodePrioritizer sorted nodes [72171219722829835-127.0.0.1:35239_solr-n_0000000005, 72171219722829836-127.0.0.1:34905_solr-n_0000000006, 72171219722829830-127.0.0.1:37819_solr-n_0000000007] [junit4] 2> 1574114 INFO (Thread-6044) [ ] o.a.s.c.OverseerNodePrioritizer asking node 72171219722829835-127.0.0.1:35239_solr-n_0000000005 to come join election at head [junit4] 2> 1574119 WARN (OverseerAutoScalingTriggerThread-72171219722829835-127.0.0.1:35239_solr-n_0000000005) [ ] o.a.s.c.a.OverseerTriggerThread OverseerTriggerThread woken up but we are closed, exiting. [junit4] 2> 1574134 INFO (qtp575407296-19366) [n:127.0.0.1:35239_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={op=rejoinAtHead&qt=/admin/cores&action=OVERSEEROP&electionNode=72171219722829835-127.0.0.1:35239_solr-n_0000000005&wt=javabin&version=2} status=0 QTime=0 [junit4] 2> 1574135 INFO (Thread-6044) [ ] o.a.s.c.OverseerNodePrioritizer asking the old first in line 72171219722829836-127.0.0.1:34905_solr-n_0000000006 to rejoin election [junit4] 2> 1574137 INFO (qtp2139899810-19368) [n:127.0.0.1:34905_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={op=rejoin&qt=/admin/cores&action=OVERSEEROP&electionNode=72171219722829836-127.0.0.1:34905_solr-n_0000000006&wt=javabin&version=2} status=0 QTime=0 [junit4] 2> 1574143 INFO (OverseerStateUpdate-72171219722829836-127.0.0.1:34905_solr-n_0000000006) [ ] o.a.s.c.Overseer Quit command received { [junit4] 2> "operation":"quit", [junit4] 2> "id":"72171219722829836-127.0.0.1:34905_solr-n_0000000006"} 127.0.0.1:34905_solr [junit4] 2> 1574144 INFO (OverseerStateUpdate-72171219722829836-127.0.0.1:34905_solr-n_0000000006) [ ] o.a.s.c.Overseer Overseer Loop exiting : 127.0.0.1:34905_solr [junit4] 2> 1574155 WARN (OverseerExitThread) [ ] o.a.s.c.Overseer I'm exiting, but I'm still the leader [junit4] 2> 1574155 INFO (OverseerExitThread) [ ] o.a.s.c.Overseer Overseer (id=72171219722829836-127.0.0.1:34905_solr-n_0000000006) closing [junit4] 2> 1574156 INFO (zkCallback-4755-thread-2) [ ] o.a.s.c.OverseerElectionContext I am going to be the leader 127.0.0.1:37819_solr [junit4] 2> 1574156 WARN (OverseerAutoScalingTriggerThread-72171219722829836-127.0.0.1:34905_solr-n_0000000006) [ ] o.a.s.c.a.OverseerTriggerThread OverseerTriggerThread has been closed, exiting. [junit4] 2> 1574156 INFO (zkCallback-4755-thread-2) [ ] o.a.s.c.Overseer Overseer (id=72171219722829830-127.0.0.1:37819_solr-n_0000000007) starting [junit4] 2> 1574156 WARN (ScheduledTrigger-7242-thread-2) [ ] o.a.s.c.a.TriggerEventQueue Exception peeking queue of trigger .auto_add_replicas [junit4] 2> java.lang.InterruptedException: null [junit4] 2> at java.lang.Object.wait(Native Method) ~[?:?] [junit4] 2> at java.lang.Object.wait(Object.java:516) ~[?:?] [junit4] 2> at org.apache.zookeeper.ClientCnxn.submitRequest(ClientCnxn.java:1409) ~[zookeeper-3.4.11.jar:3.4.11-37e277162d567b55a07d1755f0b31c32e93c01a0] [junit4] 2> at org.apache.zookeeper.ZooKeeper.getChildren(ZooKeeper.java:1533) ~[zookeeper-3.4.11.jar:3.4.11-37e277162d567b55a07d1755f0b31c32e93c01a0] [junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.lambda$getChildren$4(SolrZkClient.java:328) ~[java/:?] [junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:60) ~[java/:?] [junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.getChildren(SolrZkClient.java:328) ~[java/:?] [junit4] 2> at org.apache.solr.cloud.ZkDistributedQueue.fetchZkChildren(ZkDistributedQueue.java:410) ~[java/:?] [junit4] 2> at org.apache.solr.cloud.ZkDistributedQueue.firstChild(ZkDistributedQueue.java:387) ~[java/:?] [junit4] 2> at org.apache.solr.cloud.ZkDistributedQueue.firstElement(ZkDistributedQueue.java:504) ~[java/:?] [junit4] 2> at org.apache.solr.cloud.ZkDistributedQueue.peek(ZkDistributedQueue.java:145) ~[java/:?] [junit4] 2> at org.apache.solr.cloud.autoscaling.TriggerEventQueue.peekEvent(TriggerEventQueue.java:69) [java/:?] [junit4] 2> at org.apache.solr.cloud.autoscaling.ScheduledTriggers$TriggerWrapper.run(ScheduledTriggers.java:570) [java/:?] [junit4] 2> at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:514) [?:?] [junit4] 2> at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:305) [?:?] [junit4] 2> at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:300) [?:?] [junit4] 2> at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1167) [?:?] [junit4] 2> at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:641) [?:?] [junit4] 2> at java.lang.Thread.run(Thread.java:844) [?:?] [junit4] 2> 1574157 WARN (ScheduledTrigger-7242-thread-2) [ ] o.a.s.c.a.TriggerBase Exception getting trigger state '/autoscaling/triggerState/.auto_add_replicas' [junit4] 2> java.lang.InterruptedException: null [junit4] 2> at java.lang.Object.wait(Native Method) ~[?:?] [junit4] 2> at java.lang.Object.wait(Object.java:516) ~[?:?] [junit4] 2> at org.apache.zookeeper.ClientCnxn.submitRequest(ClientCnxn.java:1409) ~[zookeeper-3.4.11.jar:3.4.11-37e277162d567b55a07d1755f0b31c32e93c01a0] [junit4] 2> at org.apache.zookeeper.ZooKeeper.exists(ZooKeeper.java:1100) ~[zookeeper-3.4.11.jar:3.4.11-37e277162d567b55a07d1755f0b31c32e93c01a0] [junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.lambda$exists$3(SolrZkClient.java:316) ~[java/:?] [junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:60) ~[java/:?] [junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.exists(SolrZkClient.java:316) ~[java/:?] [junit4] 2> at org.apache.solr.client.solrj.impl.ZkDistribStateManager.hasData(ZkDistribStateManager.java:58) ~[java/:?] [junit4] 2> at org.apache.solr.cloud.autoscaling.TriggerBase.restoreState(TriggerBase.java:252) [java/:?] [junit4] 2> at org.apache.solr.cloud.autoscaling.ScheduledTriggers$TriggerWrapper.run(ScheduledTriggers.java:580) [java/:?] [junit4] 2> at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:514) [?:?] [junit4] 2> at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:305) [?:?] [junit4] 2> at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:300) [?:?] [junit4] 2> at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1167) [?:?] [junit4] 2> at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:641) [?:?] [junit4] 2> at java.lang.Thread.run(Thread.java:844) [?:?] [junit4] 2> 1574157 WARN (ScheduledTrigger-7242-thread-2) [ ] o.a.s.c.a.NodeLostTrigger NodeLostTrigger ran but was already closed [junit4] 2> 1574160 INFO (OverseerCollectionConfigSetProcessor-72171219722829830-127.0.0.1:37819_solr-n_0000000007) [ ] o.a.s.c.OverseerNodePrioritizer prioritizing overseer nodes at 72171219722829830-127.0.0.1:37819_solr-n_0000000007 overseer designates are [127.0.0.1:36427_solr, 127.0.0.1:35239_solr, 127.0.0.1:34905_solr] [junit4] 2> 1574160 INFO (OverseerCollectionConfigSetProcessor-72171219722829830-127.0.0.1:37819_solr-n_0000000007) [ ] o.a.s.c.OverseerNodePrioritizer sorted nodes [72171219722829830-127.0.0.1:37819_solr-n_0000000007, 72171219722829835-127.0.0.1:35239_solr-n_0000000008, 72171219722829836-127.0.0.1:34905_solr-n_0000000009] [junit4] 2> 1574170 INFO (OverseerStateUpdate-72171219722829830-127.0.0.1:37819_solr-n_0000000007) [ ] o.a.s.c.Overseer Quit command received { [junit4] 2> "operation":"quit", [junit4] 2> "id":"72171219722829830-127.0.0.1:37819_solr-n_0000000007"} 127.0.0.1:37819_solr [junit4] 2> 1574170 INFO (OverseerStateUpdate-72171219722829830-127.0.0.1:37819_solr-n_0000000007) [ ] o.a.s.c.Overseer Overseer Loop exiting : 127.0.0.1:37819_solr [junit4] 2> 1574172 WARN (OverseerExitThread) [ ] o.a.s.c.Overseer I'm exiting, but I'm still the leader [junit4] 2> 1574172 INFO (OverseerExitThread) [ ] o.a.s.c.Overseer Overseer (id=72171219722829830-127.0.0.1:37819_solr-n_0000000007) closing [junit4] 2> 1574172 WARN (OverseerAutoScalingTriggerThread-72171219722829830-127.0.0.1:37819_solr-n_0000000007) [ ] o.a.s.c.a.OverseerTriggerThread OverseerTriggerThread woken up but we are closed, exiting. [junit4] 2> 1574173 INFO (zkCallback-4769-thread-1) [ ] o.a.s.c.OverseerElectionContext I am going to be the leader 127.0.0.1:35239_solr [junit4] 2> 1574173 INFO (zkCallback-4769-thread-1) [ ] o.a.s.c.Overseer Overseer (id=72171219722829835-127.0.0.1:35239_solr-n_0000000008) starting [junit4] 2> 1589176 INFO (TEST-OverseerRolesTest.testOverseerRole-seed#[62B57CDAA5A2397]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testOverseerRole [junit4] 2> NOTE: reproduce with: ant test -Dtestcase=OverseerRolesTest -Dtests.method=testOverseerRole -Dtests.seed=62B57CDAA5A2397 -Dtests.multiplier=3 -Dtests.slow=true -Dtests.locale=haw-US -Dtests.timezone=SystemV/YST9 -Dtests.asserts=true -Dtests.file.encoding=UTF-8 [junit4] FAILURE 15.4s J2 | OverseerRolesTest.testOverseerRole <<< [junit4] > Throwable #1: java.lang.AssertionError: Timed out waiting for overseer state change [junit4] > at __randomizedtesting.SeedInfo.seed([62B57CDAA5A2397:E7E0AA5991E91546]:0) [junit4] > at org.apache.solr.cloud.OverseerRolesTest.waitForNewOverseer(OverseerRolesTest.java:63) [junit4] > at org.apache.solr.cloud.OverseerRolesTest.testOverseerRole(OverseerRolesTest.java:141) [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> 1589179 INFO (jetty-closer-4736-thread-2) [ ] o.e.j.s.AbstractConnector Stopped ServerConnector@1a45cbc1{SSL,[ssl, http/1.1]}{127.0.0.1:0} [junit4] 2> 1589179 INFO (jetty-closer-4736-thread-3) [ ] o.e.j.s.AbstractConnector Stopped ServerConnector@47dc6604{SSL,[ssl, http/1.1]}{127.0.0.1:0} [junit4] 2> 1589179 INFO (jetty-closer-4736-thread-3) [ ] o.a.s.c.CoreContainer Shutting down CoreContainer instance=1054463742 [junit4] 2> 1589179 INFO (jetty-closer-4736-thread-1) [ ] o.e.j.s.AbstractConnector Stopped ServerConnector@6901d706{SSL,[ssl, http/1.1]}{127.0.0.1:0} [junit4] 2> 1589180 INFO (jetty-closer-4736-thread-3) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.node, tag=null [junit4] 2> 1589180 INFO (jetty-closer-4736-thread-1) [ ] o.a.s.c.CoreContainer Shutting down CoreContainer instance=561087142 [junit4] 2> 1589180 INFO (jetty-closer-4736-thread-3) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@593e9cfb: rootName = solr_37819, domain = solr.node, service url = null, agent id = null] for registry solr.node / com.codahale.metrics.MetricRegistry@e661ecc [junit4] 2> 1589180 INFO (jetty-closer-4736-thread-1) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.node, tag=null [junit4] 2> 1589180 INFO (jetty-closer-4736-thread-1) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@749aa362: rootName = solr_35239, domain = solr.node, service url = null, agent id = null] for registry solr.node / com.codahale.metrics.MetricRegistry@74c579d4 [junit4] 2> 1589180 INFO (jetty-closer-4736-thread-2) [ ] o.a.s.c.CoreContainer Shutting down CoreContainer instance=1596426808 [junit4] 2> 1589180 INFO (jetty-closer-4736-thread-2) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.node, tag=null [junit4] 2> 1589180 INFO (jetty-closer-4736-thread-2) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@66cf367f: rootName = solr_34905, domain = solr.node, service url = null, agent id = null] for registry solr.node / com.codahale.metrics.MetricRegistry@7f14d6 [junit4] 2> 1589185 INFO (jetty-closer-4736-thread-1) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jvm, tag=null [junit4] 2> 1589185 INFO (jetty-closer-4736-thread-1) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@5008fbb5: rootName = solr_35239, domain = solr.jvm, service url = null, agent id = null] for registry solr.jvm / com.codahale.metrics.MetricRegistry@940aa8f [junit4] 2> 1589186 INFO (jetty-closer-4736-thread-3) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jvm, tag=null [junit4] 2> 1589186 INFO (jetty-closer-4736-thread-3) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@10cdaf09: rootName = solr_37819, domain = solr.jvm, service url = null, agent id = null] for registry solr.jvm / com.codahale.metrics.MetricRegistry@940aa8f [junit4] 2> 1589189 INFO (jetty-closer-4736-thread-2) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jvm, tag=null [junit4] 2> 1589189 INFO (jetty-closer-4736-thread-1) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jetty, tag=null [junit4] 2> 1589189 INFO (jetty-closer-4736-thread-2) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@be9e44e: rootName = solr_34905, domain = solr.jvm, service url = null, agent id = null] for registry solr.jvm / com.codahale.metrics.MetricRegistry@940aa8f [junit4] 2> 1589189 INFO (jetty-closer-4736-thread-1) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@79807806: rootName = solr_35239, domain = solr.jetty, service url = null, agent id = null] for registry solr.jetty / com.codahale.metrics.MetricRegistry@cbf85f5 [junit4] 2> 1589190 INFO (jetty-closer-4736-thread-1) [ ] o.a.s.c.ZkController Remove node as live in ZooKeeper:/live_nodes/127.0.0.1:35239_solr [junit4] 2> 1589190 INFO (zkCallback-4755-thread-2) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (2) [junit4] 2> 1589190 INFO (zkCallback-4797-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (2) [junit4] 2> 1589190 INFO (jetty-closer-4736-thread-3) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jetty, tag=null [junit4] 2> 1589190 INFO (jetty-closer-4736-thread-1) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.cluster, tag=null [junit4] 2> 1589190 INFO (jetty-closer-4736-thread-3) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@61f6ee6b: rootName = solr_37819, domain = solr.jetty, service url = null, agent id = null] for registry solr.jetty / com.codahale.metrics.MetricRegistry@cbf85f5 [junit4] 2> 1589190 INFO (zkCallback-4778-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (2) [junit4] 2> 1589190 INFO (zkCallback-4792-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (2) [junit4] 2> 1589190 INFO (zkCallback-4771-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (2) [junit4] 2> 1589191 INFO (jetty-closer-4736-thread-1) [ ] o.a.s.c.Overseer Overseer (id=72171219722829835-127.0.0.1:35239_solr-n_0000000008) closing [junit4] 2> 1589191 INFO (OverseerStateUpdate-72171219722829835-127.0.0.1:35239_solr-n_0000000008) [ ] o.a.s.c.Overseer Overseer Loop exiting : 127.0.0.1:35239_solr [junit4] 2> 1589191 INFO (zkCallback-4769-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (2) [junit4] 2> 1589192 WARN (OverseerAutoScalingTriggerThread-72171219722829835-127.0.0.1:35239_solr-n_0000000008) [ ] o.a.s.c.a.OverseerTriggerThread OverseerTriggerThread woken up but we are closed, exiting. [junit4] 2> 1589195 INFO (jetty-closer-4736-thread-3) [ ] o.a.s.c.ZkController Remove node as live in ZooKeeper:/live_nodes/127.0.0.1:37819_solr [junit4] 2> 1589195 INFO (zkCallback-4771-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (1) [junit4] 2> 1589195 INFO (zkCallback-4755-thread-2) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (1) [junit4] 2> 1589195 INFO (zkCallback-4778-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (1) [junit4] 2> 1589195 INFO (jetty-closer-4736-thread-2) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jetty, tag=null [junit4] 2> 1589195 INFO (jetty-closer-4736-thread-3) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.cluster, tag=null [junit4] 2> 1589195 INFO (zkCallback-4797-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (1) [junit4] 2> 1589195 INFO (jetty-closer-4736-thread-2) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@35b0115: rootName = solr_34905, domain = solr.jetty, service url = null, agent id = null] for registry solr.jetty / com.codahale.metrics.MetricRegistry@cbf85f5 [junit4] 2> 1589196 INFO (zkCallback-4771-thread-2) [ ] o.a.s.c.OverseerElectionContext I am going to be the leader 127.0.0.1:34905_solr [junit4] 2> 1589196 INFO (jetty-closer-4736-thread-2) [ ] o.a.s.c.ZkController Remove node as live in ZooKeeper:/live_nodes/127.0.0.1:34905_solr [junit4] 2> 1589196 INFO (jetty-closer-4736-thread-3) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@3385ec9d{/solr,null,UNAVAILABLE} [junit4] 2> 1589196 INFO (jetty-closer-4736-thread-3) [ ] o.e.j.s.session Stopped scavenging [junit4] 2> 1589197 INFO (jetty-closer-4736-thread-2) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.cluster, tag=null [junit4] 2> 1589197 INFO (zkCallback-4797-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (0) [junit4] 2> 1589197 INFO (zkCallback-4771-thread-2) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (0) [junit4] 2> 1589198 INFO (jetty-closer-4736-thread-2) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@110e59a2{/solr,null,UNAVAILABLE} [junit4] 2> 1589198 INFO (jetty-closer-4736-thread-2) [ ] o.e.j.s.session Stopped scavenging [junit4] 2> 1590695 WARN (zkCallback-4769-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> 1590695 INFO (jetty-closer-4736-thread-1) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@268ef0da{/solr,null,UNAVAILABLE} [junit4] 2> 1590696 INFO (jetty-closer-4736-thread-1) [ ] o.e.j.s.session Stopped scavenging [junit4] 2> 1590696 ERROR (SUITE-OverseerRolesTest-seed#[62B57CDAA5A2397]-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> 1590696 INFO (SUITE-OverseerRolesTest-seed#[62B57CDAA5A2397]-worker) [ ] o.a.s.c.ZkTestServer connecting to 127.0.0.1:43301 43301 [junit4] 2> 1590817 INFO (Thread-6002) [ ] o.a.s.c.ZkTestServer connecting to 127.0.0.1:43301 43301 [junit4] 2> 1590818 WARN (Thread-6002) [ ] o.a.s.c.ZkTestServer Watch limit violations: [junit4] 2> Maximum concurrent create/delete watches above limit: [junit4] 2> [junit4] 2> 9 /solr/aliases.json [junit4] 2> 4 /solr/security.json [junit4] 2> [junit4] 2> Maximum concurrent data watches above limit: [junit4] 2> [junit4] 2> 9 /solr/clusterprops.json [junit4] 2> 9 /solr/autoscaling.json [junit4] 2> 9 /solr/clusterstate.json [junit4] 2> [junit4] 2> Maximum concurrent children watches above limit: [junit4] 2> [junit4] 2> 9 /solr/autoscaling/events/.scheduled_maintenance [junit4] 2> 9 /solr/live_nodes [junit4] 2> 9 /solr/autoscaling/events/.auto_add_replicas [junit4] 2> 9 /solr/collections [junit4] 2> 9 /solr/overseer/queue-work [junit4] 2> 4 /solr/overseer/collection-queue-work [junit4] 2> 2 /solr/overseer/queue [junit4] 2> [junit4] 2> NOTE: leaving temporary files on disk at: /home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.OverseerRolesTest_62B57CDAA5A2397-001 [junit4] 2> Apr 20, 2018 9:23:02 AM com.carrotsearch.randomizedtesting.ThreadLeakControl checkThreadLeaks [junit4] 2> WARNING: Will linger awaiting termination of 1 leaked thread(s). [junit4] 2> NOTE: test params are: codec=Asserting(Lucene70): {}, docValues:{}, maxPointsInLeafNode=1217, maxMBSortInHeap=5.00232842397945, sim=Asserting(org.apache.lucene.search.similarities.AssertingSimilarity@3a71acef), locale=haw-US, timezone=SystemV/YST9 [junit4] 2> NOTE: Linux 4.13.0-37-generic amd64/Oracle Corporation 9.0.4 (64-bit)/cpus=8,threads=1,free=150931016,total=506986496 [junit4] 2> NOTE: All tests run in this JVM: [TestSolrCoreParser, TestTolerantUpdateProcessorRandomCloud, TimeZoneUtilsTest, TestJettySolrRunner, DeleteLastCustomShardedReplicaTest, URLClassifyProcessorTest, DocExpirationUpdateProcessorFactoryTest, TestScoreJoinQPNoScore, SuggesterTSTTest, TestRebalanceLeaders, TestFieldCacheSortRandom, ConvertedLegacyTest, TestGraphMLResponseWriter, HdfsNNFailoverTest, TestCoreContainer, ChangedSchemaMergeTest, TermVectorComponentTest, HdfsRestartWhileUpdatingTest, TestReplicaProperties, LeaderElectionTest, DistributedVersionInfoTest, PropertiesRequestHandlerTest, SolrTestCaseJ4Test, NodeAddedTriggerIntegrationTest, TestDFISimilarityFactory, TestPivotHelperCode, TestCopyFieldCollectionResource, JvmMetricsTest, TestCloudInspectUtil, TestBlobHandler, DistribDocExpirationUpdateProcessorTest, TestRandomCollapseQParserPlugin, SolrCLIZkUtilsTest, PingRequestHandlerTest, CursorMarkTest, CoreAdminHandlerTest, TestRandomDVFaceting, TestManagedSynonymGraphFilterFactory, TestFaceting, BasicDistributedZk2Test, TestInitParams, TestBadConfig, StatsReloadRaceTest, RegexBoostProcessorTest, OverseerModifyCollectionTest, TestLazyCores, TestSolrCLIRunExample, TestPullReplicaErrorHandling, ResponseLogComponentTest, SolrIndexMetricsTest, TestSegmentSorting, UninvertDocValuesMergePolicyTest, TestAuthorizationFramework, NumericFieldsTest, RemoteQueryErrorTest, TestLegacyTerms, TestLegacyFieldCache, TestSubQueryTransformerCrossCore, TestValueSourceCache, TestSimpleQParserPlugin, DateFieldTest, TestCloudSchemaless, SpellPossibilityIteratorTest, DateMathParserTest, UnloadDistributedZkTest, TestXmlQParserPlugin, MoveReplicaHDFSFailoverTest, SolrJmxReporterTest, TestLargeCluster, TriLevelCompositeIdRoutingTest, TestCustomDocTransformer, CdcrVersionReplicationTest, TestDFRSimilarityFactory, DisMaxRequestHandlerTest, SolrMetricManagerTest, CacheHeaderTest, FileBasedSpellCheckerTest, TestShardHandlerFactory, TestAnalyzedSuggestions, CreateCollectionCleanupTest, ReplicationFactorTest, TestClusterProperties, GraphQueryTest, TestOrdValues, HighlighterMaxOffsetTest, BaseCdcrDistributedZkTest, ClassificationUpdateProcessorIntegrationTest, SSLMigrationTest, TestConfigsApi, DistanceFunctionTest, CopyFieldTest, HdfsLockFactoryTest, SpellCheckComponentTest, DeleteShardTest, LegacyCloudClusterPropTest, TestQuerySenderListener, ClusterStateTest, IndexSchemaRuntimeFieldTest, SparseHLLTest, TestDynamicLoading, TestPointFields, TestDistributedStatsComponentCardinality, TestGraphTermsQParserPlugin, AsyncCallRequestStatusResponseTest, ConcurrentDeleteAndCreateCollectionTest, TestSkipOverseerOperations, TestUniqueKeyFieldResource, TestSolrDeletionPolicy2, ZkShardTermsTest, TestRealTimeGet, CloudMLTQParserTest, V2ApiIntegrationTest, NotRequiredUniqueKeyTest, TestConfigSetImmutable, AnalyticsMergeStrategyTest, DirectSolrSpellCheckerTest, DistributedFacetPivotLargeTest, RequestLoggingTest, TestNamedUpdateProcessors, TestOnReconnectListenerSupport, TestRecoveryHdfs, TestSolrCoreProperties, BlockJoinFacetDistribTest, TestSolrQueryResponse, TestUtils, TestFieldTypeResource, ScheduledMaintenanceTriggerTest, TestSolrXml, TestCodecSupport, OpenCloseCoreStressTest, LeaderElectionIntegrationTest, RecoveryZkTest, FullSolrCloudDistribCmdsTest, ClusterStateUpdateTest, TestRandomFaceting, TestZkChroot, ShardRoutingCustomTest, TestDistributedSearch, TestRecovery, TestHashPartitioner, TestStressReorder, TestJoin, SimpleFacetsTest, TestGroupingSearch, SolrCmdDistributorTest, BadIndexSchemaTest, TestFiltering, TestFunctionQuery, TestIndexSearcher, HighlighterTest, SoftAutoCommitTest, UniqFieldsUpdateProcessorFactoryTest, TestPartialUpdateDeduplication, CSVRequestHandlerTest, SearchHandlerTest, HighlighterConfigTest, UpdateParamsTest, TestQuerySenderNoQuery, SolrIndexConfigTest, TestMergePolicyConfig, MultiTermTest, SampleTest, MinimalSchemaTest, TestElisionMultitermQuery, TestConfig, OutputWriterTest, TestFuzzyAnalyzedSuggestions, ExternalFileFieldSortTest, TestPostingsSolrHighlighter, DirectSolrConnectionTest, TestLuceneMatchVersion, TestPhraseSuggestions, TestCharFilters, SynonymTokenizerTest, TestXIncludeConfig, TestSweetSpotSimilarityFactory, TestLMDirichletSimilarityFactory, TestLMJelinekMercerSimilarityFactory, TestIBSimilarityFactory, TestFastWriter, ResourceLoaderTest, ScriptEngineTest, OpenExchangeRatesOrgProviderTest, PreAnalyzedFieldTest, TestSystemIdResolver, TestSuggestSpellingConverter, UUIDFieldTest, CircularListTest, TestRTGBase, TestCursorMarkWithoutUniqueKey, TestDistributedMissingSort, TestSimpleTrackingShardHandler, TestTolerantSearch, TestEmbeddedSolrServerConstructors, ActionThrottleTest, AddReplicaTest, AssignBackwardCompatibilityTest, CollectionsAPISolrJTest, HttpPartitionTest, LIROnShardRestartTest, LeaderElectionContextKeyTest, LeaderFailoverAfterPartitionTest, LeaderFailureAfterFreshStartTest, MigrateRouteKeyTest, MoveReplicaTest, MultiSolrCloudTestCaseTest, OverseerRolesTest] [junit4] Completed [433/803 (1!)] on J2 in 18.70s, 1 test, 1 failure <<< FAILURES! [...truncated 45036 lines...] [repro] Jenkins log URL: https://jenkins.thetaphi.de/job/Lucene-Solr-master-Linux/21867/consoleText [repro] Revision: 48e071f350c76cd8783839199ef2b1c372919ec8 [repro] Ant options: "-Dargs=-XX:+UseCompressedOops -XX:+UseParallelGC" [repro] Repro line: ant test -Dtestcase=OverseerRolesTest -Dtests.method=testOverseerRole -Dtests.seed=62B57CDAA5A2397 -Dtests.multiplier=3 -Dtests.slow=true -Dtests.locale=haw-US -Dtests.timezone=SystemV/YST9 -Dtests.asserts=true -Dtests.file.encoding=UTF-8 [repro] ant clean [...truncated 6 lines...] [repro] Test suites by module: [repro] solr/core [repro] OverseerRolesTest [repro] ant compile-test [...truncated 3303 lines...] [repro] ant test-nocompile -Dtests.dups=5 -Dtests.maxfailures=5 -Dtests.class="*.OverseerRolesTest" -Dtests.showOutput=onerror "-Dargs=-XX:+UseCompressedOops -XX:+UseParallelGC" -Dtests.seed=62B57CDAA5A2397 -Dtests.multiplier=3 -Dtests.slow=true -Dtests.locale=haw-US -Dtests.timezone=SystemV/YST9 -Dtests.asserts=true -Dtests.file.encoding=UTF-8 [...truncated 76 lines...] [repro] Failures: [repro] 0/5 failed: org.apache.solr.cloud.OverseerRolesTest [repro] Exiting with code 0 [...truncated 40 lines...]
--------------------------------------------------------------------- To unsubscribe, e-mail: dev-unsubscr...@lucene.apache.org For additional commands, e-mail: dev-h...@lucene.apache.org