Build: http://jenkins.thetaphi.de/job/Lucene-Solr-trunk-Solaris/417/ Java: 64bit/jdk1.8.0 -XX:-UseCompressedOops -XX:+UseSerialGC
1 tests failed. FAILED: org.apache.solr.cloud.OverseerTest.testShardLeaderChange Error Message: Could not register as the leader because creating the ephemeral registration node in ZooKeeper failed Stack Trace: org.apache.solr.common.SolrException: Could not register as the leader because creating the ephemeral registration node in ZooKeeper failed at __randomizedtesting.SeedInfo.seed([F5E73FF24E2B6B9E:2BB4B80554B39E6F]:0) at org.apache.solr.cloud.ShardLeaderElectionContextBase.runLeaderProcess(ElectionContext.java:212) at org.apache.solr.cloud.LeaderElector.runIamLeaderProcess(LeaderElector.java:173) at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:138) at org.apache.solr.cloud.LeaderElector.joinElection(LeaderElector.java:310) at org.apache.solr.cloud.LeaderElector.joinElection(LeaderElector.java:219) at org.apache.solr.cloud.OverseerTest$MockZKController.publishState(OverseerTest.java:181) at org.apache.solr.cloud.OverseerTest.testShardLeaderChange(OverseerTest.java:841) 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:1764) at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:871) at com.carrotsearch.randomizedtesting.RandomizedRunner$9.evaluate(RandomizedRunner.java:907) at com.carrotsearch.randomizedtesting.RandomizedRunner$10.evaluate(RandomizedRunner.java:921) 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:367) at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:809) at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:460) at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:880) at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:781) at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:816) at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:827) 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:367) at java.lang.Thread.run(Thread.java:745) Caused by: org.apache.zookeeper.KeeperException$NodeExistsException: KeeperErrorCode = NodeExists at org.apache.zookeeper.KeeperException.create(KeeperException.java:119) at org.apache.zookeeper.ZooKeeper.multiInternal(ZooKeeper.java:949) at org.apache.zookeeper.ZooKeeper.multi(ZooKeeper.java:915) at org.apache.solr.common.cloud.SolrZkClient$11.execute(SolrZkClient.java:577) at org.apache.solr.common.cloud.SolrZkClient$11.execute(SolrZkClient.java:574) at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:60) at org.apache.solr.common.cloud.SolrZkClient.multi(SolrZkClient.java:574) at org.apache.solr.cloud.ShardLeaderElectionContextBase$1.execute(ElectionContext.java:195) at org.apache.solr.common.util.RetryUtil.retryOnThrowable(RetryUtil.java:49) at org.apache.solr.common.util.RetryUtil.retryOnThrowable(RetryUtil.java:42) at org.apache.solr.cloud.ShardLeaderElectionContextBase.runLeaderProcess(ElectionContext.java:178) ... 45 more Build Log: [...truncated 11244 lines...] [junit4] Suite: org.apache.solr.cloud.OverseerTest [junit4] 2> Creating dataDir: /export/home/jenkins/workspace/Lucene-Solr-trunk-Solaris/solr/build/solr-core/test/J0/temp/solr.cloud.OverseerTest_F5E73FF24E2B6B9E-001/init-core-data-001 [junit4] 2> 1580992 INFO (SUITE-OverseerTest-seed#[F5E73FF24E2B6B9E]-worker) [ ] o.a.s.SolrTestCaseJ4 Randomized ssl (true) and clientAuth (false) [junit4] 2> 1580992 INFO (SUITE-OverseerTest-seed#[F5E73FF24E2B6B9E]-worker) [ ] o.a.s.SolrTestCaseJ4 ####initCore [junit4] 2> 1580993 INFO (SUITE-OverseerTest-seed#[F5E73FF24E2B6B9E]-worker) [ ] o.a.s.SolrTestCaseJ4 ####initCore end [junit4] 2> 1580995 INFO (TEST-OverseerTest.testOverseerFailure-seed#[F5E73FF24E2B6B9E]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testOverseerFailure [junit4] 2> 1580995 INFO (TEST-OverseerTest.testOverseerFailure-seed#[F5E73FF24E2B6B9E]) [ ] o.a.s.c.ZkTestServer STARTING ZK TEST SERVER [junit4] 2> 1580996 INFO (Thread-4184) [ ] o.a.s.c.ZkTestServer client port:0.0.0.0/0.0.0.0:0 [junit4] 2> 1580996 INFO (Thread-4184) [ ] o.a.s.c.ZkTestServer Starting server [junit4] 2> 1581098 INFO (TEST-OverseerTest.testOverseerFailure-seed#[F5E73FF24E2B6B9E]) [ ] o.a.s.c.ZkTestServer start zk server on port:50706 [junit4] 2> 1581099 INFO (TEST-OverseerTest.testOverseerFailure-seed#[F5E73FF24E2B6B9E]) [ ] o.a.s.c.c.SolrZkClient Using default ZkCredentialsProvider [junit4] 2> 1581099 INFO (TEST-OverseerTest.testOverseerFailure-seed#[F5E73FF24E2B6B9E]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper [junit4] 2> 1581102 INFO (zkCallback-2043-thread-1) [ ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@718839c9 name:ZooKeeperConnection Watcher:127.0.0.1:50706 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4] 2> 1581102 INFO (TEST-OverseerTest.testOverseerFailure-seed#[F5E73FF24E2B6B9E]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper [junit4] 2> 1581102 INFO (TEST-OverseerTest.testOverseerFailure-seed#[F5E73FF24E2B6B9E]) [ ] o.a.s.c.c.SolrZkClient Using default ZkACLProvider [junit4] 2> 1581104 INFO (TEST-OverseerTest.testOverseerFailure-seed#[F5E73FF24E2B6B9E]) [ ] o.a.s.c.c.SolrZkClient Using default ZkCredentialsProvider [junit4] 2> 1581104 INFO (TEST-OverseerTest.testOverseerFailure-seed#[F5E73FF24E2B6B9E]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper [junit4] 2> 1581106 INFO (zkCallback-2044-thread-1) [ ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@20b256e6 name:ZooKeeperConnection Watcher:127.0.0.1:50706 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4] 2> 1581106 INFO (TEST-OverseerTest.testOverseerFailure-seed#[F5E73FF24E2B6B9E]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper [junit4] 2> 1581106 INFO (TEST-OverseerTest.testOverseerFailure-seed#[F5E73FF24E2B6B9E]) [ ] o.a.s.c.c.SolrZkClient Using default ZkACLProvider [junit4] 2> 1581106 INFO (TEST-OverseerTest.testOverseerFailure-seed#[F5E73FF24E2B6B9E]) [ ] o.a.s.c.c.SolrZkClient makePath: /solr [junit4] 2> 1581109 INFO (TEST-OverseerTest.testOverseerFailure-seed#[F5E73FF24E2B6B9E]) [ ] o.a.s.c.c.SolrZkClient Using default ZkCredentialsProvider [junit4] 2> 1581110 INFO (TEST-OverseerTest.testOverseerFailure-seed#[F5E73FF24E2B6B9E]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper [junit4] 2> 1581111 INFO (zkCallback-2045-thread-1) [ ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@2b8b5373 name:ZooKeeperConnection Watcher:127.0.0.1:50706/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4] 2> 1581111 INFO (TEST-OverseerTest.testOverseerFailure-seed#[F5E73FF24E2B6B9E]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper [junit4] 2> 1581111 INFO (TEST-OverseerTest.testOverseerFailure-seed#[F5E73FF24E2B6B9E]) [ ] o.a.s.c.c.SolrZkClient Using default ZkACLProvider [junit4] 2> 1581112 INFO (TEST-OverseerTest.testOverseerFailure-seed#[F5E73FF24E2B6B9E]) [ ] o.a.s.c.c.SolrZkClient makePath: /live_nodes [junit4] 2> 1581114 INFO (TEST-OverseerTest.testOverseerFailure-seed#[F5E73FF24E2B6B9E]) [ ] o.a.s.c.c.SolrZkClient makePath: /collections [junit4] 2> 1581116 INFO (TEST-OverseerTest.testOverseerFailure-seed#[F5E73FF24E2B6B9E]) [ ] o.a.s.c.c.SolrZkClient makePath: /aliases.json [junit4] 2> 1581118 INFO (TEST-OverseerTest.testOverseerFailure-seed#[F5E73FF24E2B6B9E]) [ ] o.a.s.c.c.SolrZkClient makePath: /clusterstate.json [junit4] 2> 1581121 INFO (TEST-OverseerTest.testOverseerFailure-seed#[F5E73FF24E2B6B9E]) [ ] o.a.s.c.c.SolrZkClient makePath: /security.json [junit4] 2> 1581122 INFO (TEST-OverseerTest.testOverseerFailure-seed#[F5E73FF24E2B6B9E]) [ ] o.a.s.c.c.ZkStateReader Updating cluster state from ZooKeeper... [junit4] 2> 1581124 INFO (TEST-OverseerTest.testOverseerFailure-seed#[F5E73FF24E2B6B9E]) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (0) [junit4] 2> 1581126 INFO (TEST-OverseerTest.testOverseerFailure-seed#[F5E73FF24E2B6B9E]) [ ] o.a.s.c.c.SolrZkClient Using default ZkCredentialsProvider [junit4] 2> 1581126 INFO (TEST-OverseerTest.testOverseerFailure-seed#[F5E73FF24E2B6B9E]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper [junit4] 2> 1581128 INFO (zkCallback-2046-thread-1) [ ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@791447d4 name:ZooKeeperConnection Watcher:127.0.0.1:50706/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4] 2> 1581128 INFO (TEST-OverseerTest.testOverseerFailure-seed#[F5E73FF24E2B6B9E]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper [junit4] 2> 1581128 INFO (TEST-OverseerTest.testOverseerFailure-seed#[F5E73FF24E2B6B9E]) [ ] o.a.s.c.c.SolrZkClient Using default ZkACLProvider [junit4] 2> 1581131 INFO (TEST-OverseerTest.testOverseerFailure-seed#[F5E73FF24E2B6B9E]) [ ] o.a.s.c.c.ZkStateReader Updating cluster state from ZooKeeper... [junit4] 2> 1581133 INFO (TEST-OverseerTest.testOverseerFailure-seed#[F5E73FF24E2B6B9E]) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (0) [junit4] 2> 1581134 INFO (TEST-OverseerTest.testOverseerFailure-seed#[F5E73FF24E2B6B9E]) [ ] o.a.s.c.c.SolrZkClient makePath: /live_nodes/node1 [junit4] 2> 1581136 INFO (zkCallback-2045-thread-1) [ ] o.a.s.c.c.ZkStateReader A live node change: [WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes], has occurred - updating... (live nodes size: [0]) [junit4] 2> 1581137 INFO (zkCallback-2046-thread-1) [ ] o.a.s.c.c.ZkStateReader A live node change: [WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes], has occurred - updating... (live nodes size: [0]) [junit4] 2> 1581138 INFO (TEST-OverseerTest.testOverseerFailure-seed#[F5E73FF24E2B6B9E]) [ ] o.a.s.c.c.SolrZkClient Using default ZkCredentialsProvider [junit4] 2> 1581138 INFO (zkCallback-2045-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1) [junit4] 2> 1581138 INFO (zkCallback-2046-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1) [junit4] 2> 1581139 INFO (TEST-OverseerTest.testOverseerFailure-seed#[F5E73FF24E2B6B9E]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper [junit4] 2> 1581140 INFO (zkCallback-2047-thread-1) [ ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@4f53b1fe name:ZooKeeperConnection Watcher:127.0.0.1:50706/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4] 2> 1581140 INFO (TEST-OverseerTest.testOverseerFailure-seed#[F5E73FF24E2B6B9E]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper [junit4] 2> 1581140 INFO (TEST-OverseerTest.testOverseerFailure-seed#[F5E73FF24E2B6B9E]) [ ] o.a.s.c.c.SolrZkClient Using default ZkACLProvider [junit4] 2> 1581141 INFO (TEST-OverseerTest.testOverseerFailure-seed#[F5E73FF24E2B6B9E]) [ ] o.a.s.u.UpdateShardHandler Creating UpdateShardHandler HTTP client with params: socketTimeout=600000&connTimeout=60000&retry=true [junit4] 2> 1581158 INFO (TEST-OverseerTest.testOverseerFailure-seed#[F5E73FF24E2B6B9E]) [ ] o.a.s.c.c.SolrZkClient makePath: /overseer_elect [junit4] 2> 1581161 INFO (TEST-OverseerTest.testOverseerFailure-seed#[F5E73FF24E2B6B9E]) [ ] o.a.s.c.c.SolrZkClient makePath: /overseer_elect/election [junit4] 2> 1581163 INFO (TEST-OverseerTest.testOverseerFailure-seed#[F5E73FF24E2B6B9E]) [ ] o.a.s.c.Overseer Overseer (id=null) closing [junit4] 2> 1581163 INFO (TEST-OverseerTest.testOverseerFailure-seed#[F5E73FF24E2B6B9E]) [ ] o.a.s.c.LeaderElector Joined leadership election with path: /overseer_elect/election/95424739772006404-127.0.0.1:50706_solr-n_0000000000 [junit4] 2> 1581164 INFO (TEST-OverseerTest.testOverseerFailure-seed#[F5E73FF24E2B6B9E]) [ ] o.a.s.c.OverseerElectionContext I am going to be the leader 127.0.0.1:50706_solr [junit4] 2> 1581164 INFO (TEST-OverseerTest.testOverseerFailure-seed#[F5E73FF24E2B6B9E]) [ ] o.a.s.c.c.SolrZkClient makePath: /overseer_elect/leader [junit4] 2> 1581166 INFO (TEST-OverseerTest.testOverseerFailure-seed#[F5E73FF24E2B6B9E]) [ ] o.a.s.c.Overseer Overseer (id=95424739772006404-127.0.0.1:50706_solr-n_0000000000) starting [junit4] 2> 1581168 INFO (TEST-OverseerTest.testOverseerFailure-seed#[F5E73FF24E2B6B9E]) [ ] o.a.s.c.c.SolrZkClient makePath: /overseer/queue [junit4] 2> 1581171 INFO (TEST-OverseerTest.testOverseerFailure-seed#[F5E73FF24E2B6B9E]) [ ] o.a.s.c.c.SolrZkClient makePath: /overseer/queue-work [junit4] 2> 1581175 INFO (TEST-OverseerTest.testOverseerFailure-seed#[F5E73FF24E2B6B9E]) [ ] o.a.s.c.c.SolrZkClient makePath: /overseer/collection-map-failure [junit4] 2> 1581177 INFO (TEST-OverseerTest.testOverseerFailure-seed#[F5E73FF24E2B6B9E]) [ ] o.a.s.c.c.SolrZkClient makePath: /overseer/collection-map-running [junit4] 2> 1581180 INFO (TEST-OverseerTest.testOverseerFailure-seed#[F5E73FF24E2B6B9E]) [ ] o.a.s.c.c.SolrZkClient makePath: /overseer/collection-map-completed [junit4] 2> 1581183 INFO (TEST-OverseerTest.testOverseerFailure-seed#[F5E73FF24E2B6B9E]) [ ] o.a.s.c.c.SolrZkClient makePath: /overseer/collection-queue-work [junit4] 2> 1581189 INFO (TEST-OverseerTest.testOverseerFailure-seed#[F5E73FF24E2B6B9E]) [ ] o.a.s.c.OverseerAutoReplicaFailoverThread Starting OverseerAutoReplicaFailoverThread autoReplicaFailoverWorkLoopDelay=10000 autoReplicaFailoverWaitAfterExpiration=30000 autoReplicaFailoverBadNodeExpiration=60000 [junit4] 2> 1581190 INFO (OverseerCollectionConfigSetProcessor-95424739772006404-127.0.0.1:50706_solr-n_0000000000) [ ] o.a.s.c.OverseerTaskProcessor Process current queue of overseer operations [junit4] 2> 1581191 INFO (OverseerStateUpdate-95424739772006404-127.0.0.1:50706_solr-n_0000000000) [ ] o.a.s.c.Overseer Starting to work on the main queue [junit4] 2> 1581192 INFO (OverseerStateUpdate-95424739772006404-127.0.0.1:50706_solr-n_0000000000) [ ] o.a.s.c.c.ZkStateReader Updating cluster state from ZooKeeper... [junit4] 2> 1581195 INFO (OverseerStateUpdate-95424739772006404-127.0.0.1:50706_solr-n_0000000000) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1) [junit4] 2> 1582195 INFO (OverseerStateUpdate-95424739772006404-127.0.0.1:50706_solr-n_0000000000) [ ] o.a.s.c.Overseer processMessage: queueSize: 1, message = { [junit4] 2> "operation":"state", [junit4] 2> "state":"recovering", [junit4] 2> "node_name":"node1", [junit4] 2> "core":"core1", [junit4] 2> "core_node_name":"core_node1", [junit4] 2> "collection":"collection1", [junit4] 2> "numShards":"1", [junit4] 2> "base_url":"http://node1/solr/"} current state version: 0 [junit4] 2> 1582195 INFO (OverseerStateUpdate-95424739772006404-127.0.0.1:50706_solr-n_0000000000) [ ] o.a.s.c.o.ReplicaMutator Update state numShards=1 message={ [junit4] 2> "operation":"state", [junit4] 2> "state":"recovering", [junit4] 2> "node_name":"node1", [junit4] 2> "core":"core1", [junit4] 2> "core_node_name":"core_node1", [junit4] 2> "collection":"collection1", [junit4] 2> "numShards":"1", [junit4] 2> "base_url":"http://node1/solr/"} [junit4] 2> 1582196 INFO (OverseerStateUpdate-95424739772006404-127.0.0.1:50706_solr-n_0000000000) [ ] o.a.s.c.o.ClusterStateMutator building a new cName: collection1 [junit4] 2> 1582196 INFO (OverseerStateUpdate-95424739772006404-127.0.0.1:50706_solr-n_0000000000) [ ] o.a.s.c.o.ReplicaMutator Assigning new node to shard shard=shard1 [junit4] 2> 1582198 INFO (zkCallback-2045-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json], has occurred - updating... (live nodes size: [1]) [junit4] 2> 1582198 INFO (zkCallback-2047-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json], has occurred - updating... (live nodes size: [1]) [junit4] 2> 1582198 INFO (zkCallback-2046-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json], has occurred - updating... (live nodes size: [1]) [junit4] 2> 1582695 INFO (TEST-OverseerTest.testOverseerFailure-seed#[F5E73FF24E2B6B9E]) [ ] o.a.s.c.c.SolrZkClient makePath: /collections/collection1/leader_elect/shard1/election [junit4] 2> 1582697 INFO (zkCallback-2046-thread-1) [ ] o.a.s.c.c.ZkStateReader A collections change: [WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/collections], has occurred - updating... [junit4] 2> 1582697 INFO (zkCallback-2045-thread-1) [ ] o.a.s.c.c.ZkStateReader A collections change: [WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/collections], has occurred - updating... [junit4] 2> 1582697 INFO (zkCallback-2047-thread-1) [ ] o.a.s.c.c.ZkStateReader A collections change: [WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/collections], has occurred - updating... [junit4] 2> 1582703 INFO (TEST-OverseerTest.testOverseerFailure-seed#[F5E73FF24E2B6B9E]) [ ] o.a.s.c.LeaderElector Joined leadership election with path: /collections/collection1/leader_elect/shard1/election/95424739772006403-node1_core1-n_0000000000 [junit4] 2> 1582705 INFO (TEST-OverseerTest.testOverseerFailure-seed#[F5E73FF24E2B6B9E]) [ ] o.a.s.c.c.SolrZkClient makePath: /collections/collection1/leaders/shard1 [junit4] 2> 1582708 INFO (TEST-OverseerTest.testOverseerFailure-seed#[F5E73FF24E2B6B9E]) [ ] o.a.s.c.ShardLeaderElectionContextBase Creating leader registration node /collections/collection1/leaders/shard1/leader after winning as /collections/collection1/leader_elect/shard1/election/95424739772006403-node1_core1-n_0000000000 [junit4] 2> 1582713 INFO (OverseerStateUpdate-95424739772006404-127.0.0.1:50706_solr-n_0000000000) [ ] o.a.s.c.Overseer processMessage: queueSize: 1, message = { [junit4] 2> "operation":"leader", [junit4] 2> "shard":"shard1", [junit4] 2> "collection":"collection1", [junit4] 2> "base_url":"http://node1/solr/", [junit4] 2> "core":"core1", [junit4] 2> "state":"active"} current state version: 1 [junit4] 2> 1582713 INFO (TEST-OverseerTest.testOverseerFailure-seed#[F5E73FF24E2B6B9E]) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (1) [junit4] 2> 1582716 INFO (TEST-OverseerTest.testOverseerFailure-seed#[F5E73FF24E2B6B9E]) [ ] o.a.s.c.ElectionContext Canceling election /collections/collection1/leader_elect/shard1/election/95424739772006403-node1_core1-n_0000000000 [junit4] 2> 1582717 INFO (TEST-OverseerTest.testOverseerFailure-seed#[F5E73FF24E2B6B9E]) [ ] o.a.s.c.ShardLeaderElectionContextBase Removing leader registration node on cancel: /collections/collection1/leaders/shard1/leader 1 [junit4] 2> 1582718 INFO (TEST-OverseerTest.testOverseerFailure-seed#[F5E73FF24E2B6B9E]) [ ] o.a.s.c.c.SolrZkClient makePath: /collections/collection1/leader_elect/shard1/election [junit4] 2> 1582718 INFO (OverseerStateUpdate-95424739772006404-127.0.0.1:50706_solr-n_0000000000) [ ] o.a.s.c.Overseer processMessage: queueSize: 1, message = { [junit4] 2> "operation":"state", [junit4] 2> "state":"active", [junit4] 2> "node_name":"node1", [junit4] 2> "core":"core1", [junit4] 2> "core_node_name":"core_node1", [junit4] 2> "collection":"collection1", [junit4] 2> "numShards":"1", [junit4] 2> "base_url":"http://node1/solr/"} current state version: 1 [junit4] 2> 1582719 INFO (OverseerStateUpdate-95424739772006404-127.0.0.1:50706_solr-n_0000000000) [ ] o.a.s.c.o.ReplicaMutator Update state numShards=1 message={ [junit4] 2> "operation":"state", [junit4] 2> "state":"active", [junit4] 2> "node_name":"node1", [junit4] 2> "core":"core1", [junit4] 2> "core_node_name":"core_node1", [junit4] 2> "collection":"collection1", [junit4] 2> "numShards":"1", [junit4] 2> "base_url":"http://node1/solr/"} [junit4] 2> 1582719 INFO (OverseerStateUpdate-95424739772006404-127.0.0.1:50706_solr-n_0000000000) [ ] o.a.s.c.o.ReplicaMutator shard=shard1 is already registered [junit4] 2> 1582724 INFO (TEST-OverseerTest.testOverseerFailure-seed#[F5E73FF24E2B6B9E]) [ ] o.a.s.c.LeaderElector Joined leadership election with path: /collections/collection1/leader_elect/shard1/election/95424739772006403-node1_core1-n_0000000001 [junit4] 2> 1582725 INFO (TEST-OverseerTest.testOverseerFailure-seed#[F5E73FF24E2B6B9E]) [ ] o.a.s.c.ShardLeaderElectionContextBase Creating leader registration node /collections/collection1/leaders/shard1/leader after winning as /collections/collection1/leader_elect/shard1/election/95424739772006403-node1_core1-n_0000000001 [junit4] 2> 1582730 INFO (OverseerStateUpdate-95424739772006404-127.0.0.1:50706_solr-n_0000000000) [ ] o.a.s.c.Overseer processMessage: queueSize: 1, message = { [junit4] 2> "operation":"leader", [junit4] 2> "shard":"shard1", [junit4] 2> "collection":"collection1", [junit4] 2> "base_url":"http://node1/solr/", [junit4] 2> "core":"core1", [junit4] 2> "state":"active"} current state version: 1 [junit4] 2> 1582834 INFO (zkCallback-2045-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json], has occurred - updating... (live nodes size: [1]) [junit4] 2> 1582834 INFO (zkCallback-2046-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json], has occurred - updating... (live nodes size: [1]) [junit4] 2> 1582835 INFO (zkCallback-2047-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json], has occurred - updating... (live nodes size: [1]) [junit4] 2> 1583196 INFO (OverseerCollectionConfigSetProcessor-95424739772006404-127.0.0.1:50706_solr-n_0000000000) [ ] o.a.s.c.OverseerTaskProcessor [junit4] 2> org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /overseer_elect/leader [junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:127) [junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:51) [junit4] 2> at org.apache.zookeeper.ZooKeeper.getData(ZooKeeper.java:1155) [junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:353) [junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:350) [junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:60) [junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.getData(SolrZkClient.java:350) [junit4] 2> at org.apache.solr.cloud.OverseerTaskProcessor.amILeader(OverseerTaskProcessor.java:354) [junit4] 2> at org.apache.solr.cloud.OverseerTaskProcessor.run(OverseerTaskProcessor.java:171) [junit4] 2> at java.lang.Thread.run(Thread.java:745) [junit4] 2> 1583196 INFO (OverseerCollectionConfigSetProcessor-95424739772006404-127.0.0.1:50706_solr-n_0000000000) [ ] o.a.s.c.OverseerTaskProcessor According to ZK I (id=95424739772006404-127.0.0.1:50706_solr-n_0000000000) am no longer a leader. [junit4] 2> 1583890 INFO (TEST-OverseerTest.testOverseerFailure-seed#[F5E73FF24E2B6B9E]) [ ] o.a.s.c.ElectionContext Canceling election /collections/collection1/leader_elect/shard1/election/95424739772006403-node1_core1-n_0000000001 [junit4] 2> 1583891 INFO (TEST-OverseerTest.testOverseerFailure-seed#[F5E73FF24E2B6B9E]) [ ] o.a.s.c.ShardLeaderElectionContextBase Removing leader registration node on cancel: /collections/collection1/leaders/shard1/leader 2 [junit4] 2> 1583892 INFO (TEST-OverseerTest.testOverseerFailure-seed#[F5E73FF24E2B6B9E]) [ ] o.a.s.c.c.SolrZkClient makePath: /collections/collection1/leader_elect/shard1/election [junit4] 2> 1583898 INFO (TEST-OverseerTest.testOverseerFailure-seed#[F5E73FF24E2B6B9E]) [ ] o.a.s.c.LeaderElector Joined leadership election with path: /collections/collection1/leader_elect/shard1/election/95424739772006403-node1_core1-n_0000000002 [junit4] 2> 1583899 INFO (TEST-OverseerTest.testOverseerFailure-seed#[F5E73FF24E2B6B9E]) [ ] o.a.s.c.ShardLeaderElectionContextBase Creating leader registration node /collections/collection1/leaders/shard1/leader after winning as /collections/collection1/leader_elect/shard1/election/95424739772006403-node1_core1-n_0000000002 [junit4] 2> 1583903 INFO (TEST-OverseerTest.testOverseerFailure-seed#[F5E73FF24E2B6B9E]) [ ] o.a.s.c.c.SolrZkClient Using default ZkCredentialsProvider [junit4] 2> 1583903 INFO (TEST-OverseerTest.testOverseerFailure-seed#[F5E73FF24E2B6B9E]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper [junit4] 2> 1583905 INFO (zkCallback-2050-thread-1) [ ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@71494ee3 name:ZooKeeperConnection Watcher:127.0.0.1:50706/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4] 2> 1583905 INFO (TEST-OverseerTest.testOverseerFailure-seed#[F5E73FF24E2B6B9E]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper [junit4] 2> 1583905 INFO (TEST-OverseerTest.testOverseerFailure-seed#[F5E73FF24E2B6B9E]) [ ] o.a.s.c.c.SolrZkClient Using default ZkACLProvider [junit4] 2> 1583905 INFO (TEST-OverseerTest.testOverseerFailure-seed#[F5E73FF24E2B6B9E]) [ ] o.a.s.c.Overseer Overseer (id=95424739772006404-127.0.0.1:50706_solr-n_0000000000) closing [junit4] 2> 1583906 INFO (TEST-OverseerTest.testOverseerFailure-seed#[F5E73FF24E2B6B9E]) [ ] o.a.s.u.UpdateShardHandler Creating UpdateShardHandler HTTP client with params: socketTimeout=600000&connTimeout=60000&retry=true [junit4] 2> 1583906 INFO (OverseerStateUpdate-95424739772006404-127.0.0.1:50706_solr-n_0000000000) [ ] o.a.s.c.Overseer Overseer Loop exiting : 127.0.0.1:50706_solr [junit4] 2> 1583908 ERROR (OverseerExitThread) [ ] o.a.s.c.Overseer could not read the data [junit4] 2> org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /overseer_elect/leader [junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:127) [junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:51) [junit4] 2> at org.apache.zookeeper.ZooKeeper.getData(ZooKeeper.java:1155) [junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:353) [junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:350) [junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:60) [junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.getData(SolrZkClient.java:350) [junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.checkIfIamStillLeader(Overseer.java:308) [junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.access$300(Overseer.java:89) [junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater$2.run(Overseer.java:267) [junit4] 2> 1583912 INFO (TEST-OverseerTest.testOverseerFailure-seed#[F5E73FF24E2B6B9E]) [ ] o.a.s.c.Overseer Overseer (id=null) closing [junit4] 2> 1583912 INFO (TEST-OverseerTest.testOverseerFailure-seed#[F5E73FF24E2B6B9E]) [ ] o.a.s.c.LeaderElector Joined leadership election with path: /overseer_elect/election/95424739772006405-127.0.0.1:50706_solr-n_0000000001 [junit4] 2> 1583913 INFO (TEST-OverseerTest.testOverseerFailure-seed#[F5E73FF24E2B6B9E]) [ ] o.a.s.c.OverseerElectionContext I am going to be the leader 127.0.0.1:50706_solr [junit4] 2> 1583913 INFO (TEST-OverseerTest.testOverseerFailure-seed#[F5E73FF24E2B6B9E]) [ ] o.a.s.c.c.SolrZkClient makePath: /overseer_elect/leader [junit4] 2> 1583915 INFO (TEST-OverseerTest.testOverseerFailure-seed#[F5E73FF24E2B6B9E]) [ ] o.a.s.c.Overseer Overseer (id=95424739772006405-127.0.0.1:50706_solr-n_0000000001) starting [junit4] 2> 1583926 INFO (TEST-OverseerTest.testOverseerFailure-seed#[F5E73FF24E2B6B9E]) [ ] o.a.s.c.OverseerAutoReplicaFailoverThread Starting OverseerAutoReplicaFailoverThread autoReplicaFailoverWorkLoopDelay=10000 autoReplicaFailoverWaitAfterExpiration=30000 autoReplicaFailoverBadNodeExpiration=60000 [junit4] 2> 1583926 INFO (OverseerCollectionConfigSetProcessor-95424739772006405-127.0.0.1:50706_solr-n_0000000001) [ ] o.a.s.c.OverseerTaskProcessor Process current queue of overseer operations [junit4] 2> 1583928 INFO (OverseerStateUpdate-95424739772006405-127.0.0.1:50706_solr-n_0000000001) [ ] o.a.s.c.Overseer Starting to work on the main queue [junit4] 2> 1583929 INFO (OverseerStateUpdate-95424739772006405-127.0.0.1:50706_solr-n_0000000001) [ ] o.a.s.c.c.ZkStateReader Updating cluster state from ZooKeeper... [junit4] 2> 1583931 INFO (OverseerStateUpdate-95424739772006405-127.0.0.1:50706_solr-n_0000000001) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1) [junit4] 2> 1583934 INFO (OverseerStateUpdate-95424739772006405-127.0.0.1:50706_solr-n_0000000001) [ ] o.a.s.c.Overseer processMessage: queueSize: 2, message = { [junit4] 2> "operation":"state", [junit4] 2> "state":"recovering", [junit4] 2> "node_name":"node1", [junit4] 2> "core":"core1", [junit4] 2> "core_node_name":"core_node1", [junit4] 2> "collection":"collection1", [junit4] 2> "numShards":"1", [junit4] 2> "base_url":"http://node1/solr/"} current state version: 2 [junit4] 2> 1583935 INFO (OverseerStateUpdate-95424739772006405-127.0.0.1:50706_solr-n_0000000001) [ ] o.a.s.c.o.ReplicaMutator Update state numShards=1 message={ [junit4] 2> "operation":"state", [junit4] 2> "state":"recovering", [junit4] 2> "node_name":"node1", [junit4] 2> "core":"core1", [junit4] 2> "core_node_name":"core_node1", [junit4] 2> "collection":"collection1", [junit4] 2> "numShards":"1", [junit4] 2> "base_url":"http://node1/solr/"} [junit4] 2> 1583935 INFO (OverseerStateUpdate-95424739772006405-127.0.0.1:50706_solr-n_0000000001) [ ] o.a.s.c.o.ReplicaMutator shard=shard1 is already registered [junit4] 2> 1583937 INFO (zkCallback-2045-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json], has occurred - updating... (live nodes size: [1]) [junit4] 2> 1583937 INFO (zkCallback-2050-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json], has occurred - updating... (live nodes size: [1]) [junit4] 2> 1583937 INFO (zkCallback-2046-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json], has occurred - updating... (live nodes size: [1]) [junit4] 2> 1583943 INFO (OverseerStateUpdate-95424739772006405-127.0.0.1:50706_solr-n_0000000001) [ ] o.a.s.c.Overseer processMessage: queueSize: 0, message = { [junit4] 2> "operation":"leader", [junit4] 2> "shard":"shard1", [junit4] 2> "collection":"collection1", [junit4] 2> "base_url":"http://node1/solr/", [junit4] 2> "core":"core1", [junit4] 2> "state":"active"} current state version: 3 [junit4] 2> 1583988 INFO (TEST-OverseerTest.testOverseerFailure-seed#[F5E73FF24E2B6B9E]) [ ] o.a.s.c.ElectionContext Canceling election /collections/collection1/leader_elect/shard1/election/95424739772006403-node1_core1-n_0000000002 [junit4] 2> 1583989 INFO (TEST-OverseerTest.testOverseerFailure-seed#[F5E73FF24E2B6B9E]) [ ] o.a.s.c.ShardLeaderElectionContextBase Removing leader registration node on cancel: /collections/collection1/leaders/shard1/leader 3 [junit4] 2> 1583993 INFO (OverseerStateUpdate-95424739772006405-127.0.0.1:50706_solr-n_0000000001) [ ] o.a.s.c.Overseer processMessage: queueSize: 1, message = { [junit4] 2> "operation":"deletecore", [junit4] 2> "node_name":"node1", [junit4] 2> "core":"core1", [junit4] 2> "core_node_name":"core_node1", [junit4] 2> "collection":"collection1"} current state version: 3 [junit4] 2> 1584097 INFO (zkCallback-2050-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json], has occurred - updating... (live nodes size: [1]) [junit4] 2> 1584098 INFO (zkCallback-2045-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json], has occurred - updating... (live nodes size: [1]) [junit4] 2> 1584097 INFO (zkCallback-2046-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json], has occurred - updating... (live nodes size: [1]) [junit4] 2> 1584600 INFO (zkCallback-2046-thread-1) [ ] o.a.s.c.c.ZkStateReader A live node change: [WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes], has occurred - updating... (live nodes size: [1]) [junit4] 2> 1584600 INFO (zkCallback-2045-thread-1) [ ] o.a.s.c.c.ZkStateReader A live node change: [WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes], has occurred - updating... (live nodes size: [1]) [junit4] 2> 1584601 INFO (zkCallback-2050-thread-1) [ ] o.a.s.c.c.ZkStateReader A live node change: [WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes], has occurred - updating... (live nodes size: [1]) [junit4] 2> 1584601 INFO (zkCallback-2046-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (0) [junit4] 2> 1584601 INFO (zkCallback-2050-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (0) [junit4] 2> 1584602 INFO (zkCallback-2045-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (0) [junit4] 2> 1584602 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 0x153044b94e50003, likely client has closed socket [junit4] 2> at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:228) [junit4] 2> at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208) [junit4] 2> at java.lang.Thread.run(Thread.java:745) [junit4] 2> 1584604 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 0x153044b94e50005, likely client has closed socket [junit4] 2> at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:228) [junit4] 2> at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208) [junit4] 2> at java.lang.Thread.run(Thread.java:745) [junit4] 2> 1584606 INFO (TEST-OverseerTest.testOverseerFailure-seed#[F5E73FF24E2B6B9E]) [ ] o.a.s.c.ZkTestServer connecting to 127.0.0.1:50706 50706 [junit4] 2> 1584667 INFO (Thread-4184) [ ] o.a.s.c.ZkTestServer connecting to 127.0.0.1:50706 50706 [junit4] 2> 1584670 WARN (Thread-4184) [ ] o.a.s.c.ZkTestServer Watch limit violations: [junit4] 2> Maximum concurrent create/delete watches above limit: [junit4] 2> [junit4] 2> 4 /solr/aliases.json [junit4] 2> [junit4] 2> Maximum concurrent data watches above limit: [junit4] 2> [junit4] 2> 4 /solr/clusterstate.json [junit4] 2> [junit4] 2> Maximum concurrent children watches above limit: [junit4] 2> [junit4] 2> 4 /solr/live_nodes [junit4] 2> 4 /solr/collections [junit4] 2> 2 /solr/overseer/queue [junit4] 2> 2 /solr/overseer/collection-queue-work [junit4] 2> 2 /solr/overseer/queue-work [junit4] 2> [junit4] 2> 1584670 INFO (TEST-OverseerTest.testOverseerFailure-seed#[F5E73FF24E2B6B9E]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testOverseerFailure [junit4] 2> 1584670 INFO (TEST-OverseerTest.testOverseerFailure-seed#[F5E73FF24E2B6B9E]) [ ] o.a.s.c.Overseer Overseer (id=95424739772006405-127.0.0.1:50706_solr-n_0000000001) closing [junit4] 2> 1584670 INFO (OverseerStateUpdate-95424739772006405-127.0.0.1:50706_solr-n_0000000001) [ ] o.a.s.c.Overseer Overseer Loop exiting : 127.0.0.1:50706_solr [junit4] 2> 1584675 ERROR (OverseerExitThread) [ ] o.a.s.c.Overseer could not read the data [junit4] 2> org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /overseer_elect/leader [junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:127) [junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:51) [junit4] 2> at org.apache.zookeeper.ZooKeeper.getData(ZooKeeper.java:1155) [junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:353) [junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:350) [junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:60) [junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.getData(SolrZkClient.java:350) [junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.checkIfIamStillLeader(Overseer.java:308) [junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.access$300(Overseer.java:89) [junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater$2.run(Overseer.java:267) [junit4] 2> 1584678 INFO (TEST-OverseerTest.testPlaceholders-seed#[F5E73FF24E2B6B9E]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testPlaceholders [junit4] 2> 1584690 INFO (TEST-OverseerTest.testPlaceholders-seed#[F5E73FF24E2B6B9E]) [ ] o.a.s.c.ZkTestServer STARTING ZK TEST SERVER [junit4] 2> 1584691 INFO (Thread-4185) [ ] o.a.s.c.ZkTestServer client port:0.0.0.0/0.0.0.0:0 [junit4] 2> 1584691 INFO (Thread-4185) [ ] o.a.s.c.ZkTestServer Starting server [junit4] 2> 1584791 INFO (TEST-OverseerTest.testPlaceholders-seed#[F5E73FF24E2B6B9E]) [ ] o.a.s.c.ZkTestServer start zk server on port:54173 [junit4] 2> 1584791 INFO (TEST-OverseerTest.testPlaceholders-seed#[F5E73FF24E2B6B9E]) [ ] o.a.s.c.c.SolrZkClient Using default ZkCredentialsProvider [junit4] 2> 1584792 INFO (TEST-OverseerTest.testPlaceholders-seed#[F5E73FF24E2B6B9E]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper [junit4] 2> 1584796 INFO (zkCallback-2053-thread-1) [ ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@185d613f name:ZooKeeperConnection Watcher:127.0.0.1:54173/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4] 2> 1584796 INFO (TEST-OverseerTest.testPlaceholders-seed#[F5E73FF24E2B6B9E]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper [junit4] 2> 1584796 INFO (TEST-OverseerTest.testPlaceholders-seed#[F5E73FF24E2B6B9E]) [ ] o.a.s.c.c.SolrZkClient Using default ZkACLProvider [junit4] 2> 1584796 INFO (TEST-OverseerTest.testPlaceholders-seed#[F5E73FF24E2B6B9E]) [ ] o.a.s.c.c.SolrZkClient Using default ZkCredentialsProvider [junit4] 2> 1584797 INFO (TEST-OverseerTest.testPlaceholders-seed#[F5E73FF24E2B6B9E]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper [junit4] 2> 1584798 INFO (zkCallback-2054-thread-1) [ ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@336cb4c6 name:ZooKeeperConnection Watcher:127.0.0.1:54173 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4] 2> 1584799 INFO (TEST-OverseerTest.testPlaceholders-seed#[F5E73FF24E2B6B9E]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper [junit4] 2> 1584799 INFO (TEST-OverseerTest.testPlaceholders-seed#[F5E73FF24E2B6B9E]) [ ] o.a.s.c.c.SolrZkClient Using default ZkACLProvider [junit4] 2> 1584800 INFO (TEST-OverseerTest.testPlaceholders-seed#[F5E73FF24E2B6B9E]) [ ] o.a.s.c.c.SolrZkClient Using default ZkCredentialsProvider [junit4] 2> 1584801 INFO (TEST-OverseerTest.testPlaceholders-seed#[F5E73FF24E2B6B9E]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper [junit4] 2> 1584802 INFO (zkCallback-2055-thread-1) [ ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@1ed50662 name:ZooKeeperConnection Watcher:127.0.0.1:54173 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4] 2> 1584802 INFO (TEST-OverseerTest.testPlaceholders-seed#[F5E73FF24E2B6B9E]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper [junit4] 2> 1584803 INFO (TEST-OverseerTest.testPlaceholders-seed#[F5E73FF24E2B6B9E]) [ ] o.a.s.c.c.SolrZkClient Using default ZkACLProvider [junit4] 2> 1584803 INFO (TEST-OverseerTest.testPlaceholders-seed#[F5E73FF24E2B6B9E]) [ ] o.a.s.c.c.SolrZkClient makePath: /solr [junit4] 2> 1584807 INFO (TEST-OverseerTest.testPlaceholders-seed#[F5E73FF24E2B6B9E]) [ ] o.a.s.c.c.SolrZkClient makePath: /live_nodes [junit4] 2> 1584810 INFO (TEST-OverseerTest.testPlaceholders-seed#[F5E73FF24E2B6B9E]) [ ] o.a.s.c.c.SolrZkClient makePath: /collections [junit4] 2> 1584812 INFO (TEST-OverseerTest.testPlaceholders-seed#[F5E73FF24E2B6B9E]) [ ] o.a.s.c.c.SolrZkClient makePath: /aliases.json [junit4] 2> 1584814 INFO (TEST-OverseerTest.testPlaceholders-seed#[F5E73FF24E2B6B9E]) [ ] o.a.s.c.c.SolrZkClient makePath: /clusterstate.json [junit4] 2> 1584816 INFO (TEST-OverseerTest.testPlaceholders-seed#[F5E73FF24E2B6B9E]) [ ] o.a.s.c.c.SolrZkClient makePath: /security.json [junit4] 2> 1584818 INFO (TEST-OverseerTest.testPlaceholders-seed#[F5E73FF24E2B6B9E]) [ ] o.a.s.c.c.ZkStateReader Updating cluster state from ZooKeeper... [junit4] 2> 1584820 INFO (TEST-OverseerTest.testPlaceholders-seed#[F5E73FF24E2B6B9E]) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (0) [junit4] 2> 1584822 INFO (TEST-OverseerTest.testPlaceholders-seed#[F5E73FF24E2B6B9E]) [ ] o.a.s.c.c.SolrZkClient Using default ZkCredentialsProvider [junit4] 2> 1584823 INFO (TEST-OverseerTest.testPlaceholders-seed#[F5E73FF24E2B6B9E]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper [junit4] 2> 1584824 INFO (zkCallback-2056-thread-1) [ ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@3710ff29 name:ZooKeeperConnection Watcher:127.0.0.1:54173/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4] 2> 1584824 INFO (TEST-OverseerTest.testPlaceholders-seed#[F5E73FF24E2B6B9E]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper [junit4] 2> 1584824 INFO (TEST-OverseerTest.testPlaceholders-seed#[F5E73FF24E2B6B9E]) [ ] o.a.s.c.c.SolrZkClient Using default ZkACLProvider [junit4] 2> 1584826 INFO (TEST-OverseerTest.testPlaceholders-seed#[F5E73FF24E2B6B9E]) [ ] o.a.s.c.c.ZkStateReader Updating cluster state from ZooKeeper... [junit4] 2> 1584829 INFO (TEST-OverseerTest.testPlaceholders-seed#[F5E73FF24E2B6B9E]) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (0) [junit4] 2> 1584830 INFO (TEST-OverseerTest.testPlaceholders-seed#[F5E73FF24E2B6B9E]) [ ] o.a.s.c.c.SolrZkClient makePath: /live_nodes/node1 [junit4] 2> 1584832 INFO (zkCallback-2053-thread-1) [ ] o.a.s.c.c.ZkStateReader A live node change: [WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes], has occurred - updating... (live nodes size: [0]) [junit4] 2> 1584832 INFO (zkCallback-2056-thread-1) [ ] o.a.s.c.c.ZkStateReader A live node change: [WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes], has occurred - updating... (live nodes size: [0]) [junit4] 2> 1584833 INFO (TEST-OverseerTest.testPlaceholders-seed#[F5E73FF24E2B6B9E]) [ ] o.a.s.c.c.SolrZkClient Using default ZkCredentialsProvider [junit4] 2> 1584834 INFO (zkCallback-2053-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1) [junit4] 2> 1584834 INFO (TEST-OverseerTest.testPlaceholders-seed#[F5E73FF24E2B6B9E]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper [junit4] 2> 1584835 INFO (zkCallback-2056-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1) [junit4] 2> 1584837 INFO (zkCallback-2057-thread-1) [ ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@3492323e name:ZooKeeperConnection Watcher:127.0.0.1:54173/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4] 2> 1584837 INFO (TEST-OverseerTest.testPlaceholders-seed#[F5E73FF24E2B6B9E]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper [junit4] 2> 1584837 INFO (TEST-OverseerTest.testPlaceholders-seed#[F5E73FF24E2B6B9E]) [ ] o.a.s.c.c.SolrZkClient Using default ZkACLProvider [junit4] 2> 1584837 INFO (TEST-OverseerTest.testPlaceholders-seed#[F5E73FF24E2B6B9E]) [ ] o.a.s.u.UpdateShardHandler Creating UpdateShardHandler HTTP client with params: socketTimeout=600000&connTimeout=60000&retry=true [junit4] 2> 1584840 INFO (TEST-OverseerTest.testPlaceholders-seed#[F5E73FF24E2B6B9E]) [ ] o.a.s.c.c.SolrZkClient makePath: /overseer_elect [junit4] 2> 1584842 INFO (TEST-OverseerTest.testPlaceholders-seed#[F5E73FF24E2B6B9E]) [ ] o.a.s.c.c.SolrZkClient makePath: /overseer_elect/election [junit4] 2> 1584843 INFO (TEST-OverseerTest.testPlaceholders-seed#[F5E73FF24E2B6B9E]) [ ] o.a.s.c.Overseer Overseer (id=null) closing [junit4] 2> 1584844 INFO (TEST-OverseerTest.testPlaceholders-seed#[F5E73FF24E2B6B9E]) [ ] o.a.s.c.LeaderElector Joined leadership election with path: /overseer_elect/election/95424740014227460-127.0.0.1:54173_solr-n_0000000000 [junit4] 2> 1584844 INFO (TEST-OverseerTest.testPlaceholders-seed#[F5E73FF24E2B6B9E]) [ ] o.a.s.c.OverseerElectionContext I am going to be the leader 127.0.0.1:54173_solr [junit4] 2> 1584844 INFO (TEST-OverseerTest.testPlaceholders-seed#[F5E73FF24E2B6B9E]) [ ] o.a.s.c.c.SolrZkClient makePath: /overseer_elect/leader [junit4] 2> 1584846 INFO (TEST-OverseerTest.testPlaceholders-seed#[F5E73FF24E2B6B9E]) [ ] o.a.s.c.Overseer Overseer (id=95424740014227460-127.0.0.1:54173_solr-n_0000000000) starting [junit4] 2> 1584848 INFO (TEST-OverseerTest.testPlaceholders-seed#[F5E73FF24E2B6B9E]) [ ] o.a.s.c.c.SolrZkClient makePath: /overseer/queue [junit4] 2> 1584853 INFO (TEST-OverseerTest.testPlaceholders-seed#[F5E73FF24E2B6B9E]) [ ] o.a.s.c.c.SolrZkClient makePath: /overseer/queue-work [junit4] 2> 1584856 INFO (TEST-OverseerTest.testPlaceholders-seed#[F5E73FF24E2B6B9E]) [ ] o.a.s.c.c.SolrZkClient makePath: /overseer/collection-map-failure [junit4] 2> 1584859 INFO (TEST-OverseerTest.testPlaceholders-seed#[F5E73FF24E2B6B9E]) [ ] o.a.s.c.c.SolrZkClient makePath: /overseer/collection-map-running [junit4] 2> 1584863 INFO (TEST-OverseerTest.testPlaceholders-seed#[F5E73FF24E2B6B9E]) [ ] o.a.s.c.c.SolrZkClient makePath: /overseer/collection-map-completed [junit4] 2> 1584866 INFO (TEST-OverseerTest.testPlaceholders-seed#[F5E73FF24E2B6B9E]) [ ] o.a.s.c.c.SolrZkClient makePath: /overseer/collection-queue-work [junit4] 2> 1584872 INFO (TEST-OverseerTest.testPlaceholders-seed#[F5E73FF24E2B6B9E]) [ ] o.a.s.c.OverseerAutoReplicaFailoverThread Starting OverseerAutoReplicaFailoverThread autoReplicaFailoverWorkLoopDelay=10000 autoReplicaFailoverWaitAfterExpiration=30000 autoReplicaFailoverBadNodeExpiration=60000 [junit4] 2> 1584873 INFO (OverseerCollectionConfigSetProcessor-95424740014227460-127.0.0.1:54173_solr-n_0000000000) [ ] o.a.s.c.OverseerTaskProcessor Process current queue of overseer operations [junit4] 2> 1584874 INFO (OverseerStateUpdate-95424740014227460-127.0.0.1:54173_solr-n_0000000000) [ ] o.a.s.c.Overseer Starting to work on the main queue [junit4] 2> 1584875 INFO (OverseerStateUpdate-95424740014227460-127.0.0.1:54173_solr-n_0000000000) [ ] o.a.s.c.c.ZkStateReader Updating cluster state from ZooKeeper... [junit4] 2> 1584878 INFO (OverseerStateUpdate-95424740014227460-127.0.0.1:54173_solr-n_0000000000) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1) [junit4] 2> 1584880 INFO (OverseerStateUpdate-95424740014227460-127.0.0.1:54173_solr-n_0000000000) [ ] o.a.s.c.Overseer processMessage: queueSize: 1, message = { [junit4] 2> "operation":"state", [junit4] 2> "state":"recovering", [junit4] 2> "node_name":"node1", [junit4] 2> "core":"core1", [junit4] 2> "core_node_name":"node1", [junit4] 2> "collection":"collection1", [junit4] 2> "numShards":"12", [junit4] 2> "base_url":"http://node1/solr/"} current state version: 0 [junit4] 2> 1584881 INFO (OverseerStateUpdate-95424740014227460-127.0.0.1:54173_solr-n_0000000000) [ ] o.a.s.c.o.ReplicaMutator Update state numShards=12 message={ [junit4] 2> "operation":"state", [junit4] 2> "state":"recovering", [junit4] 2> "node_name":"node1", [junit4] 2> "core":"core1", [junit4] 2> "core_node_name":"node1", [junit4] 2> "collection":"collection1", [junit4] 2> "numShards":"12", [junit4] 2> "base_url":"http://node1/solr/"} [junit4] 2> 1584881 INFO (OverseerStateUpdate-95424740014227460-127.0.0.1:54173_solr-n_0000000000) [ ] o.a.s.c.o.ClusterStateMutator building a new cName: collection1 [junit4] 2> 1584881 INFO (OverseerStateUpdate-95424740014227460-127.0.0.1:54173_solr-n_0000000000) [ ] o.a.s.c.o.ReplicaMutator Assigning new node to shard shard=shard2 [junit4] 2> 1584883 INFO (zkCallback-2053-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json], has occurred - updating... (live nodes size: [1]) [junit4] 2> 1584883 INFO (zkCallback-2057-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json], has occurred - updating... (live nodes size: [1]) [junit4] 2> 1584883 INFO (zkCallback-2056-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json], has occurred - updating... (live nodes size: [1]) [junit4] 2> 1585376 INFO (TEST-OverseerTest.testPlaceholders-seed#[F5E73FF24E2B6B9E]) [ ] o.a.s.c.c.SolrZkClient makePath: /collections/collection1/leader_elect/shard2/election [junit4] 2> 1585378 INFO (zkCallback-2057-thread-1) [ ] o.a.s.c.c.ZkStateReader A collections change: [WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/collections], has occurred - updating... [junit4] 2> 1585379 INFO (zkCallback-2053-thread-1) [ ] o.a.s.c.c.ZkStateReader A collections change: [WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/collections], has occurred - updating... [junit4] 2> 1585379 INFO (zkCallback-2056-thread-1) [ ] o.a.s.c.c.ZkStateReader A collections change: [WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/collections], has occurred - updating... [junit4] 2> 1585384 INFO (TEST-OverseerTest.testPlaceholders-seed#[F5E73FF24E2B6B9E]) [ ] o.a.s.c.LeaderElector Joined leadership election with path: /collections/collection1/leader_elect/shard2/election/95424740014227459-node1_core1-n_0000000000 [junit4] 2> 1585385 INFO (TEST-OverseerTest.testPlaceholders-seed#[F5E73FF24E2B6B9E]) [ ] o.a.s.c.c.SolrZkClient makePath: /collections/collection1/leaders/shard2 [junit4] 2> 1585389 INFO (TEST-OverseerTest.testPlaceholders-seed#[F5E73FF24E2B6B9E]) [ ] o.a.s.c.ShardLeaderElectionContextBase Creating leader registration node /collections/collection1/leaders/shard2/leader after winning as /collections/collection1/leader_elect/shard2/election/95424740014227459-node1_core1-n_0000000000 [junit4] 2> 1585392 INFO (OverseerStateUpdate-95424740014227460-127.0.0.1:54173_solr-n_0000000000) [ ] o.a.s.c.Overseer processMessage: queueSize: 1, message = { [junit4] 2> "operation":"leader", [junit4] 2> "shard":"shard2", [junit4] 2> "collection":"collection1", [junit4] 2> "base_url":"http://node1/solr/", [junit4] 2> "core":"core1", [junit4] 2> "state":"active"} current state version: 1 [junit4] 2> 1585394 INFO (TEST-OverseerTest.testPlaceholders-seed#[F5E73FF24E2B6B9E]) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (1) [junit4] 2> 1585395 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 0x153044ba3550004, likely client has closed socket [junit4] 2> at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:228) [junit4] 2> at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208) [junit4] 2> at java.lang.Thread.run(Thread.java:745) [junit4] 2> 1585396 INFO (zkCallback-2056-thread-1) [ ] o.a.s.c.c.ZkStateReader A live node change: [WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes], has occurred - updating... (live nodes size: [1]) [junit4] 2> 1585396 INFO (zkCallback-2053-thread-1) [ ] o.a.s.c.c.ZkStateReader A live node change: [WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes], has occurred - updating... (live nodes size: [1]) [junit4] 2> 1585397 INFO (zkCallback-2053-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (0) [junit4] 2> 1585397 INFO (zkCallback-2056-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (0) [junit4] 2> 1585398 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 0x153044ba3550003, likely client has closed socket [junit4] 2> at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:228) [junit4] 2> at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208) [junit4] 2> at java.lang.Thread.run(Thread.java:745) [junit4] 2> 1585400 INFO (TEST-OverseerTest.testPlaceholders-seed#[F5E73FF24E2B6B9E]) [ ] o.a.s.c.ZkTestServer connecting to 127.0.0.1:54173 54173 [junit4] 2> 1585418 INFO (Thread-4185) [ ] o.a.s.c.ZkTestServer connecting to 127.0.0.1:54173 54173 [junit4] 2> 1585421 WARN (Thread-4185) [ ] o.a.s.c.ZkTestServer Watch limit violations: [junit4] 2> Maximum concurrent create/delete watches above limit: [junit4] 2> [junit4] 2> 3 /solr/aliases.json [junit4] 2> [junit4] 2> Maximum concurrent data watches above limit: [junit4] 2> [junit4] 2> 3 /solr/clusterstate.json [junit4] 2> [junit4] 2> Maximum concurrent children watches above limit: [junit4] 2> [junit4] 2> 3 /solr/live_nodes [junit4] 2> 3 /solr/collections [junit4] 2> [junit4] 2> 1585421 INFO (TEST-OverseerTest.testPlaceholders-seed#[F5E73FF24E2B6B9E]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testPlaceholders [junit4] 2> 1585421 INFO (TEST-OverseerTest.testPlaceholders-seed#[F5E73FF24E2B6B9E]) [ ] o.a.s.c.Overseer Overseer (id=95424740014227460-127.0.0.1:54173_solr-n_0000000000) closing [junit4] 2> 1585421 INFO (OverseerStateUpdate-95424740014227460-127.0.0.1:54173_solr-n_0000000000) [ ] o.a.s.c.Overseer Overseer Loop exiting : 127.0.0.1:54173_solr [junit4] 2> 1585425 ERROR (OverseerExitThread) [ ] o.a.s.c.Overseer could not read the data [junit4] 2> org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /overseer_elect/leader [junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:127) [junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:51) [junit4] 2> at org.apache.zookeeper.ZooKeeper.getData(ZooKeeper.java:1155) [junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:353) [junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:350) [junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:60) [junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.getData(SolrZkClient.java:350) [junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.checkIfIamStillLeader(Overseer.java:308) [junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.access$300(Overseer.java:89) [junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater$2.run(Overseer.java:267) [junit4] 2> 1585431 INFO (TEST-OverseerTest.testRemovalOfLastReplica-seed#[F5E73FF24E2B6B9E]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testRemovalOfLastReplica [junit4] 2> 1585431 INFO (TEST-OverseerTest.testRemovalOfLastReplica-seed#[F5E73FF24E2B6B9E]) [ ] o.a.s.c.ZkTestServer STARTING ZK TEST SERVER [junit4] 2> 1585431 INFO (Thread-4186) [ ] o.a.s.c.ZkTestServer client port:0.0.0.0/0.0.0.0:0 [junit4] 2> 1585431 INFO (Thread-4186) [ ] o.a.s.c.ZkTestServer Starting server [junit4] 2> 1585531 INFO (TEST-OverseerTest.testRemovalOfLastReplica-seed#[F5E73FF24E2B6B9E]) [ ] o.a.s.c.ZkTestServer start zk server on port:56594 [junit4] 2> 1585532 INFO (TEST-OverseerTest.testRemovalOfLastReplica-seed#[F5E73FF24E2B6B9E]) [ ] o.a.s.c.c.SolrZkClient Using default ZkCredentialsProvider [junit4] 2> 1585532 INFO (TEST-OverseerTest.testRemovalOfLastReplica-seed#[F5E73FF24E2B6B9E]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper [junit4] 2> 1585535 INFO (zkCallback-2060-thread-1) [ ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@ee5794c name:ZooKeeperConnection Watcher:127.0.0.1:56594 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4] 2> 1585535 INFO (TEST-OverseerTest.testRemovalOfLastReplica-seed#[F5E73FF24E2B6B9E]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper [junit4] 2> 1585535 INFO (TEST-OverseerTest.testRemovalOfLastReplica-seed#[F5E73FF24E2B6B9E]) [ ] o.a.s.c.c.SolrZkClient Using default ZkACLProvider [junit4] 2> 1585537 INFO (TEST-OverseerTest.testRemovalOfLastReplica-seed#[F5E73FF24E2B6B9E]) [ ] o.a.s.c.c.SolrZkClient Using default ZkCredentialsProvider [junit4] 2> 1585538 INFO (TEST-OverseerTest.testRemovalOfLastReplica-seed#[F5E73FF24E2B6B9E]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper [junit4] 2> 1585539 INFO (zkCallback-2061-thread-1) [ ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@69aeb749 name:ZooKeeperConnection Watcher:127.0.0.1:56594 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4] 2> 1585539 INFO (TEST-OverseerTest.testRemovalOfLastReplica-seed#[F5E73FF24E2B6B9E]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper [junit4] 2> 1585539 INFO (TEST-OverseerTest.testRemovalOfLastReplica-seed#[F5E73FF24E2B6B9E]) [ ] o.a.s.c.c.SolrZkClient Using default ZkACLProvider [junit4] 2> 1585539 INFO (TEST-OverseerTest.testRemovalOfLastReplica-seed#[F5E73FF24E2B6B9E]) [ ] o.a.s.c.c.SolrZkClient makePath: /solr [junit4] 2> 1585543 INFO (TEST-OverseerTest.testRemovalOfLastReplica-seed#[F5E73FF24E2B6B9E]) [ ] o.a.s.c.c.SolrZkClient Using default ZkCredentialsProvider [junit4] 2> 1585543 INFO (TEST-OverseerTest.testRemovalOfLastReplica-seed#[F5E73FF24E2B6B9E]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper [junit4] 2> 1585545 INFO (zkCallback-2062-thread-1) [ ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@f68a660 name:ZooKeeperConnection Watcher:127.0.0.1:56594/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4] 2> 1585545 INFO (TEST-OverseerTest.testRemovalOfLastReplica-seed#[F5E73FF24E2B6B9E]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper [junit4] 2> 1585545 INFO (TEST-OverseerTest.testRemovalOfLastReplica-seed#[F5E73FF24E2B6B9E]) [ ] o.a.s.c.c.SolrZkClient Using default ZkACLProvider [junit4] 2> 1585546 INFO (TEST-OverseerTest.testRemovalOfLastReplica-seed#[F5E73FF24E2B6B9E]) [ ] o.a.s.c.c.SolrZkClient makePath: /live_nodes [junit4] 2> 1585547 INFO (TEST-OverseerTest.testRemovalOfLastReplica-seed#[F5E73FF24E2B6B9E]) [ ] o.a.s.c.c.SolrZkClient makePath: /collections [junit4] 2> 1585550 INFO (TEST-OverseerTest.testRemovalOfLastReplica-seed#[F5E73FF24E2B6B9E]) [ ] o.a.s.c.c.SolrZkClient makePath: /aliases.json [junit4] 2> 1585551 INFO (TEST-OverseerTest.testRemovalOfLastReplica-seed#[F5E73FF24E2B6B9E]) [ ] o.a.s.c.c.SolrZkClient makePath: /clusterstate.json [junit4] 2> 1585553 INFO (TEST-OverseerTest.testRemovalOfLastReplica-seed#[F5E73FF24E2B6B9E]) [ ] o.a.s.c.c.SolrZkClient makePath: /security.json [junit4] 2> 1585555 INFO (TEST-OverseerTest.testRemovalOfLastReplica-seed#[F5E73FF24E2B6B9E]) [ ] o.a.s.c.c.ZkStateReader Updating cluster state from ZooKeeper... [junit4] 2> 1585556 INFO (TEST-OverseerTest.testRemovalOfLastReplica-seed#[F5E73FF24E2B6B9E]) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (0) [junit4] 2> 1585557 INFO (TEST-OverseerTest.testRemovalOfLastReplica-seed#[F5E73FF24E2B6B9E]) [ ] o.a.s.c.c.SolrZkClient Using default ZkCredentialsProvider [junit4] 2> 1585558 INFO (TEST-OverseerTest.testRemovalOfLastReplica-seed#[F5E73FF24E2B6B9E]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper [junit4] 2> 1585559 INFO (zkCallback-2063-thread-1) [ ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@370e49da name:ZooKeeperConnection Watcher:127.0.0.1:56594/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4] 2> 1585559 INFO (TEST-OverseerTest.testRemovalOfLastReplica-seed#[F5E73FF24E2B6B9E]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper [junit4] 2> 1585559 INFO (TEST-OverseerTest.testRemovalOfLastReplica-seed#[F5E73FF24E2B6B9E]) [ ] o.a.s.c.c.SolrZkClient Using default ZkACLProvider [junit4] 2> 1585559 INFO (TEST-OverseerTest.testRemovalOfLastReplica-seed#[F5E73FF24E2B6B9E]) [ ] o.a.s.u.UpdateShardHandler Creating UpdateShardHandler HTTP client with params: socketTimeout=600000&connTimeout=60000&retry=true [junit4] 2> 1585562 INFO (TEST-OverseerTest.testRemovalOfLastReplica-seed#[F5E73FF24E2B6B9E]) [ ] o.a.s.c.c.SolrZkClient makePath: /overseer_elect [junit4] 2> 1585564 INFO (TEST-OverseerTest.testRemovalOfLastReplica-seed#[F5E73FF24E2B6B9E]) [ ] o.a.s.c.c.SolrZkClient makePath: /overseer_elect/election [junit4] 2> 1585566 INFO (TEST-OverseerTest.testRemovalOfLastReplica-seed#[F5E73FF24E2B6B9E]) [ ] o.a.s.c.Overseer Overseer (id=null) closing [junit4] 2> 1585567 INFO (TEST-OverseerTest.testRemovalOfLastReplica-seed#[F5E73FF24E2B6B9E]) [ ] o.a.s.c.LeaderElector Joined leadership election with path: /overseer_elect/election/95424740062724099-127.0.0.1:56594_solr-n_0000000000 [junit4] 2> 1585567 INFO (TEST-OverseerTest.testRemovalOfLastReplica-seed#[F5E73FF24E2B6B9E]) [ ] o.a.s.c.OverseerElectionContext I am going to be the leader 127.0.0.1:56594_solr [junit4] 2> 1585567 INFO (TEST-OverseerTest.testRemovalOfLastReplica-seed#[F5E73FF24E2B6B9E]) [ ] o.a.s.c.c.SolrZkClient makePath: /overseer_elect/leader [junit4] 2> 1585569 INFO (TEST-OverseerTest.testRemovalOfLastReplica-seed#[F5E73FF24E2B6B9E]) [ ] o.a.s.c.Overseer Overseer (id=95424740062724099-127.0.0.1:56594_solr-n_0000000000) starting [junit4] 2> 1585570 INFO (TEST-OverseerTest.testRemovalOfLastReplica-seed#[F5E73FF24E2B6B9E]) [ ] o.a.s.c.c.SolrZkClient makePath: /overseer/queue [junit4] 2> 1585573 INFO (TEST-OverseerTest.testRemovalOfLastReplica-seed#[F5E73FF24E2B6B9E]) [ ] o.a.s.c.c.SolrZkClient makePath: /overseer/queue-work [junit4] 2> 1585576 INFO (TEST-OverseerTest.testRemovalOfLastReplica-seed#[F5E73FF24E2B6B9E]) [ ] o.a.s.c.c.SolrZkClient makePath: /overseer/collection-map-failure [junit4] 2> 1585578 INFO (TEST-OverseerTest.testRemovalOfLastReplica-seed#[F5E73FF24E2B6B9E]) [ ] o.a.s.c.c.SolrZkClient makePath: /overseer/collection-map-running [junit4] 2> 1585581 INFO (TEST-OverseerTest.testRemovalOfLastReplica-seed#[F5E73FF24E2B6B9E]) [ ] o.a.s.c.c.SolrZkClient makePath: /overseer/collection-map-completed [junit4] 2> 1585584 INFO (TEST-OverseerTest.testRemovalOfLastReplica-seed#[F5E73FF24E2B6B9E]) [ ] o.a.s.c.c.SolrZkClient makePath: /overseer/collection-queue-work [junit4] 2> 1585589 INFO (TEST-OverseerTest.testRemovalOfLastReplica-seed#[F5E73FF24E2B6B9E]) [ ] o.a.s.c.OverseerAutoReplicaFailoverThread Starting OverseerAutoReplicaFailoverThread autoReplicaFailoverWorkLoopDelay=10000 autoReplicaFailoverWaitAfterExpiration=30000 autoReplicaFailoverBadNodeExpiration=60000 [junit4] 2> 1585589 INFO (OverseerCollectionConfigSetProcessor-95424740062724099-127.0.0.1:56594_solr-n_0000000000) [ ] o.a.s.c.OverseerTaskProcessor Process current queue of overseer operations [junit4] 2> 1585590 INFO (OverseerStateUpdate-95424740062724099-127.0.0.1:56594_solr-n_0000000000) [ ] o.a.s.c.Overseer Starting to work on the main queue [junit4] 2> 1585590 INFO (OverseerStateUpdate-95424740062724099-127.0.0.1:56594_solr-n_0000000000) [ ] o.a.s.c.c.ZkStateReader Updating cluster state from ZooKeeper... [junit4] 2> 1585593 INFO (OverseerStateUpdate-95424740062724099-127.0.0.1:56594_solr-n_0000000000) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (0) [junit4] 2> 1585593 INFO (TEST-OverseerTest.testRemovalOfLastReplica-seed#[F5E73FF24E2B6B9E]) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (0) [junit4] 2> 1585595 INFO (OverseerStateUpdate-95424740062724099-127.0.0.1:56594_solr-n_0000000000) [ ] o.a.s.c.Overseer processMessage: queueSize: 1, message = { [junit4] 2> "operation":"create", [junit4] 2> "name":"collection1", [junit4] 2> "numShards":"4", [junit4] 2> "replicationFactor":"1", [junit4] 2> "maxShardsPerNode":"8"} current state version: 0 [junit4] 2> 1585595 INFO (OverseerStateUpdate-95424740062724099-127.0.0.1:56594_solr-n_0000000000) [ ] o.a.s.c.o.ClusterStateMutator building a new cName: collection1 [junit4] 2> 1585597 INFO (zkCallback-2063-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json], has occurred - updating... (live nodes size: [0]) [junit4] 2> 1585597 INFO (zkCallback-2062-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json], has occurred - updating... (live nodes size: [0]) [junit4] 2> 1585645 INFO (TEST-OverseerTest.testRemovalOfLastReplica-seed#[F5E73FF24E2B6B9E]) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (0) [junit4] 2> 1585647 INFO (OverseerStateUpdate-95424740062724099-127.0.0.1:56594_solr-n_0000000000) [ ] o.a.s.c.Overseer processMessage: queueSize: 1, message = { [junit4] 2> "operation":"state", [junit4] 2> "base_url":"http://127.0.0.1/solr", [junit4] 2> "shard":"shard1", [junit4] 2> "node_name":"node5", [junit4] 2> "collection":"collection1", [junit4] 2> "core":"core5", [junit4] 2> "roles":"", [junit4] 2> "state":"recovering"} current state version: 1 [junit4] 2> 1585648 INFO (OverseerStateUpdate-95424740062724099-127.0.0.1:56594_solr-n_0000000000) [ ] o.a.s.c.o.ReplicaMutator Update state numShards=null message={ [junit4] 2> "operation":"state", [junit4] 2> "base_url":"http://127.0.0.1/solr", [junit4] 2> "shard":"shard1", [junit4] 2> "node_name":"node5", [junit4] 2> "collection":"collection1", [junit4] 2> "core":"core5", [junit4] 2> "roles":"", [junit4] 2> "state":"recovering"} [junit4] 2> 1585653 INFO (OverseerStateUpdate-95424740062724099-127.0.0.1:56594_solr-n_0000000000) [ ] o.a.s.c.Overseer processMessage: queueSize: 7, message = { [junit4] 2> "operation":"state", [junit4] 2> "base_url":"http://127.0.0.1/solr", [junit4] 2> "shard":"shard2", [junit4] 2> "node_name":"node6", [junit4] 2> "collection":"collection1", [junit4] 2> "core":"core6", [junit4] 2> "roles":"", [junit4] 2> "state":"recovering"} current state version: 1 [junit4] 2> 1585654 INFO (OverseerStateUpdate-95424740062724099-127.0.0.1:56594_solr-n_0000000000) [ ] o.a.s.c.o.ReplicaMutator Update state numShards=null message={ [junit4] 2> "operation":"state", [junit4] 2> "base_url":"http://127.0.0.1/solr", [junit4] 2> "shard":"shard2", [junit4] 2> "node_name":"node6", [junit4] 2> "collection":"collection1", [junit4] 2> "core":"core6", [junit4] 2> "roles":"", [junit4] 2> "state":"recovering"} [junit4] 2> 1585657 INFO (OverseerStateUpdate-95424740062724099-127.0.0.1:56594_solr-n_0000000000) [ ] o.a.s.c.Overseer processMessage: queueSize: 7, message = { [junit4] 2> "operation":"state", [junit4] 2> "base_url":"http://127.0.0.1/solr", [junit4] 2> "shard":"shard3", [junit4] 2> "node_name":"node7", [junit4] 2> "collection":"collection1", [junit4] 2> "core":"core7", [junit4] 2> "roles":"", [junit4] 2> "state":"recovering"} current state version: 1 [junit4] 2> 1585658 INFO (OverseerStateUpdate-95424740062724099-127.0.0.1:56594_solr-n_0000000000) [ ] o.a.s.c.o.ReplicaMutator Update state numShards=null message={ [junit4] 2> "operation":"state", [junit4] 2> "base_url":"http://127.0.0.1/solr", [junit4] 2> "shard":"shard3", [junit4] 2> "node_name":"node7", [junit4] 2> "collection":"collection1", [junit4] 2> "core":"core7", [junit4] 2> "roles":"", [junit4] 2> "state":"recovering"} [junit4] 2> 1585661 INFO (OverseerStateUpdate-95424740062724099-127.0.0.1:56594_solr-n_0000000000) [ ] o.a.s.c.Overseer processMessage: queueSize: 7, message = { [junit4] 2> "operation":"state", [junit4] 2> "base_url":"http://127.0.0.1/solr", [junit4] 2> "shard":"shard4", [junit4] 2> "node_name":"node8", [junit4] 2> "collection":"collection1", [junit4] 2> "core":"core8", [junit4] 2> "roles":"", [junit4] 2> "state":"recovering"} current state version: 1 [junit4] 2> 1585662 INFO (OverseerStateUpdate-95424740062724099-127.0.0.1:56594_solr-n_0000000000) [ ] o.a.s.c.o.ReplicaMutator Update state numShards=null message={ [junit4] 2> "operation":"state", [junit4] 2> "base_url":"http://127.0.0.1/solr", [junit4] 2> "shard":"shard4", [junit4] 2> "node_name":"node8", [junit4] 2> "collection":"collection1", [junit4] 2> "core":"core8", [junit4] 2> "roles":"", [junit4] 2> "state":"recovering"} [junit4] 2> 1585664 INFO (OverseerStateUpdate-95424740062724099-127.0.0.1:56594_solr-n_0000000000) [ ] o.a.s.c.Overseer processMessage: queueSize: 7, message = { [junit4] 2> "operation":"state", [junit4] 2> "base_url":"http://127.0.0.1/solr", [junit4] 2> "shard":"shard1", [junit4] 2> "node_name":"node1", [junit4] 2> "collection":"collection1", [junit4] 2> "core":"core1", [junit4] 2> "roles":"", [junit4] 2> "state":"recovering"} current state version: 1 [junit4] 2> 1585665 INFO (OverseerStateUpdate-95424740062724099-127.0.0.1:56594_solr-n_0000000000) [ ] o.a.s.c.o.ReplicaMutator Update state numShards=null message={ [junit4] 2> "operation":"state", [junit4] 2> "base_url":"http://127.0.0.1/solr", [junit4] 2> "shard":"shard1", [junit4] 2> "node_name":"node1", [junit4] 2> "collection":"collection1", [junit4] 2> "core":"core1", [junit4] 2> "roles":"", [junit4] 2> "state":"recovering"} [junit4] 2> 1585668 INFO (OverseerStateUpdate-95424740062724099-127.0.0.1:56594_solr-n_0000000000) [ ] o.a.s.c.Overseer processMessage: queueSize: 7, message = { [junit4] 2> "operation":"state", [junit4] 2> "base_url":"http://127.0.0.1/solr", [junit4] 2> "shard":"shard2", [junit4] 2> "node_name":"node2", [junit4] 2> "collection":"collection1", [junit4] 2> "core":"core2", [junit4] 2> "roles":"", [junit4] 2> "state":"recovering"} current state version: 1 [junit4] 2> 1585669 INFO (OverseerStateUpdate-95424740062724099-127.0.0.1:56594_solr-n_0000000000) [ ] o.a.s.c.o.ReplicaMutator Update state numShards=null message={ [junit4] 2> "operation":"state", [junit4] 2> "base_url":"http://127.0.0.1/solr", [junit4] 2> "shard":"shard2", [junit4] 2> "node_name":"node2", [junit4] 2> "collection":"collection1", [junit4] 2> "core":"core2", [junit4] 2> "roles":"", [junit4] 2> "state":"recovering"} [junit4] 2> 1585672 INFO (OverseerStateUpdate-95424740062724099-127.0.0.1:56594_solr-n_0000000000) [ ] o.a.s.c.Overseer processMessage: queueSize: 7, message = { [junit4] 2> "operation":"state", [junit4] 2> "base_url":"http://127.0.0.1/solr", [junit4] 2> "shard":"shard3", [junit4] 2> "node_name":"node3", [junit4] 2> "collection":"collection1", [junit4] 2> "core":"core3", [junit4] 2> "roles":"", [junit4] 2> "state":"recovering"} current state version: 1 [junit4] 2> 1585673 INFO (OverseerStateUpdate-95424740062724099-127.0.0.1:56594_solr-n_0000000000) [ ] o.a.s.c.o.ReplicaMutator Update state numShards=null message={ [junit4] 2> "operation":"state", [junit4] 2> "base_url":"http://127.0.0.1/solr", [junit4] 2> "shard":"shard3", [junit4] 2> "node_name":"node3", [junit4] 2> "collection":"collection1", [junit4] 2> "core":"core3", [junit4] 2> "roles":"", [junit4] 2> "state":"recovering"} [junit4] 2> 1585676 INFO (OverseerStateUpdate-95424740062724099-127.0.0.1:56594_solr-n_0000000000) [ ] o.a.s.c.Overseer processMessage: queueSize: 7, message = { [junit4] 2> "operation":"state", [junit4] 2> "base_url":"http://127.0.0.1/solr", [junit4] 2> "shard":"shard4", [junit4] 2> "node_name":"node4", [junit4] 2> "collection":"collection1", [junit4] 2> "core":"core4", [junit4] 2> "roles":"", [junit4] 2> "state":"recovering"} current state version: 1 [junit4] 2> 1585677 INFO (OverseerStateUpdate-95424740062724099-127.0.0.1:56594_solr-n_0000000000) [ ] o.a.s.c.o.ReplicaMutator Update state numShards=null message={ [junit4] 2> "operation":"state", [junit4] 2> "base_url":"http://127.0.0.1/solr", [junit4] 2> "shard":"shard4", [junit4] 2> "node_name":"node4", [junit4] 2> "collection":"collection1", [junit4] 2> "core":"core4", [junit4] 2> "roles":"", [junit4] 2> "state":"recovering"} [junit4] 2> 1585780 INFO (zkCallback-2062-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json], has occurred - updating... (live nodes size: [0]) [junit4] 2> 1585781 INFO (zkCallback-2063-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json], has occurred - updating... (live nodes size: [0]) [junit4] 2> 1585805 INFO (OverseerStateUpdate-95424740062724099-127.0.0.1:56594_solr-n_0000000000) [ ] o.a.s.c.Overseer processMessage: queueSize: 2, message = { [junit4] 2> "operation":"state", [junit4] 2> "base_url":"http://127.0.0.1/solr", [junit4] 2> "node_name":"node5", [junit4] 2> "collection":"collection1", [junit4] 2> "core":"core5", [junit4] 2> "roles":"", [junit4] 2> "state":"active"} current state version: 2 [junit4] 2> 1585806 INFO (OverseerStateUpdate-95424740062724099-127.0.0.1:56594_solr-n_0000000000) [ ] o.a.s.c.o.ReplicaMutator Update state numShards=null message={ [junit4] 2> "operation":"state", [junit4] 2> "base_url":"http://127.0.0.1/solr", [junit4] 2> "node_name":"node5", [junit4] 2> "collection":"collection1", [junit4] 2> "core":"core5", [junit4] 2> "roles":"", [junit4] 2> "state":"active"} [junit4] 2> 1585806 INFO (OverseerStateUpdate-95424740062724099-127.0.0.1:56594_solr-n_0000000000) [ ] o.a.s.c.o.ReplicaMutator node=core_node1 is already registered [junit4] 2> 1585806 INFO (OverseerStateUpdate-95424740062724099-127.0.0.1:56594_solr-n_0000000000) [ ] o.a.s.c.o.ReplicaMutator shard=shard1 is already registered [junit4] 2> 1585809 INFO (OverseerStateUpdate-95424740062724099-127.0.0.1:56594_solr-n_0000000000) [ ] o.a.s.c.Overseer processMessage: queueSize: 2, message = { [junit4] 2> "operation":"state", [junit4] 2> "base_url":"http://127.0.0.1/solr", [junit4] 2> "node_name":"node6", [junit4] 2> "collection":"collection1", [junit4] 2> "core":"core6", [junit4] 2> "roles":"", [junit4] 2> "state":"active"} current state version: 2 [junit4] 2> 1585810 INFO (OverseerStateUpdate-95424740062724099-127.0.0.1:56594_solr-n_0000000000) [ ] o.a.s.c.o.ReplicaMutator Update state numShards=null message={ [junit4] 2> "operation":"state", [junit4] 2> "base_url":"http://127.0.0.1/solr", [junit4] 2> "node_name":"node6", [junit4] 2> "collection":"collection1", [junit4] 2> "core":"core6", [junit4] 2> "roles":"", [junit4] 2> "state":"active"} [junit4] 2> 1585810 INFO (OverseerStateUpdate-95424740062724099-127.0.0.1:56594_solr-n_0000000000) [ ] o.a.s.c.o.ReplicaMutator node=core_node2 is already registered [junit4] 2> 1585810 INFO (OverseerStateUpdate-95424740062724099-127.0.0.1:56594_solr-n_0000000000) [ ] o.a.s.c.o.ReplicaMutator shard=shard2 is already registered [junit4] 2> 1585814 INFO (OverseerStateUpdate-95424740062724099-127.0.0.1:56594_solr-n_0000000000) [ ] o.a.s.c.Overseer processMessage: queueSize: 6, message = { [junit4] 2> "operation":"state", [junit4] 2> "base_url":"http://127.0.0.1/solr", [junit4] 2> "node_name":"node7", [junit4] 2> "collection":"collection1", [junit4] 2> "core":"core7", [junit4] 2> "roles":"", [junit4] 2> "state":"active"} current state version: 2 [junit4] 2> 1585815 INFO (OverseerStateUpdate-95424740062724099-127.0.0.1:56594_solr-n_0000000000) [ ] o.a.s.c.o.ReplicaMutator Update state numShards=null message={ [junit4] 2> "operation":"state", [junit4] 2> "base_url":"http://127.0.0.1/solr", [junit4] 2> "node_name":"node7", [junit4] 2> "collection":"collection1", [junit4] 2> "core":"core7", [junit4] 2> "roles":"", [junit4] 2> "state":"active"} [junit4] 2> 1585815 INFO (OverseerStateUpdate-95424740062724099-127.0.0.1:56594_solr-n_0000000000) [ ] o.a.s.c.o.ReplicaMutator node=core_node3 is already registered [junit4] 2> 1585815 INFO (OverseerStateUpdate-95424740062724099-127.0.0.1:56594_solr-n_0000000000) [ ] o.a.s.c.o.ReplicaMutator shard=shard3 is already registered [junit4] 2> 1585817 INFO (OverseerStateUpdate-95424740062724099-127.0.0.1:56594_solr-n_0000000000) [ ] o.a.s.c.Overseer processMessage: queueSize: 6, message = { [junit4] 2> "operation":"state", [junit4] 2> "base_url":"http://127.0.0.1/solr", [junit4] 2> "node_name":"node8", [junit4] 2> "collection":"collection1", [junit4] 2> "core":"core8", [junit4] 2> "roles":"", [junit4] 2> "state":"active"} current state version: 2 [junit4] 2> 1585818 INFO (OverseerStateUpdate-95424740062724099-127.0.0.1:56594_solr-n_0000000000) [ ] o.a.s.c.o.ReplicaMutator Update state numShards=null message={ [junit4] 2> "operation":"state", [junit4] 2> "base_url":"http://127.0.0.1/solr", [junit4] 2> "node_name":"node8", [junit4] 2> "collection":"collection1", [junit4] 2> "core":"core8", [junit4] 2> "roles":"", [junit4] 2> "state":"active"} [junit4] 2> 1585818 INFO (OverseerStateUpdate-95424740062724099-127.0.0.1:56594_solr-n_0000000000) [ ] o.a.s.c.o.ReplicaMutator node=core_node4 is already registered [junit4] 2> 1585818 INFO (OverseerStateUpdate-95424740062724099-127.0.0.1:56594_solr-n_0000000000) [ ] o.a.s.c.o.ReplicaMutator shard=shard4 is already registered [junit4] 2> 1585821 INFO (OverseerStateUpdate-95424740062724099-127.0.0.1:56594_solr-n_0000000000) [ ] o.a.s.c.Overseer processMessage: queueSize: 6, message = { [junit4] 2> "operation":"state", [junit4] 2> "base_url":"http://127.0.0.1/solr", [junit4] 2> "node_name":"node1", [junit4] 2> "collection":"collection1", [junit4] 2> "core":"core1", [junit4] 2> "roles":"", [junit4] 2> "state":"active"} current state version: 2 [junit4] 2> 1585821 INFO (OverseerStateUpdate-95424740062724099-127.0.0.1:56594_solr-n_0000000000) [ ] o.a.s.c.o.ReplicaMutator Update state numShards=null message={ [junit4] 2> "operation":"state", [junit4] 2> "base_url":"http://127.0.0.1/solr", [junit4] 2> "node_name":"node1", [junit4] 2> "collection":"collection1", [junit4] 2> "core":"core1", [junit4] 2> "roles":"", [junit4] 2> "state":"active"} [junit4] 2> 1585821 INFO (OverseerStateUpdate-95424740062724099-127.0.0.1:56594_solr-n_0000000000) [ ] o.a.s.c.o.ReplicaMutator node=core_node5 is already registered [junit4] 2> 1585821 INFO (OverseerStateUpdate-95424740062724099-127.0.0.1:56594_solr-n_0000000000) [ ] o.a.s.c.o.ReplicaMutator shard=shard1 is already registered [junit4] 2> 1585823 INFO (OverseerStateUpdate-95424740062724099-127.0.0.1:56594_solr-n_0000000000) [ ] o.a.s.c.Overseer processMessage: queueSize: 6, message = { [junit4] 2> "operation":"state", [junit4] 2> "base_url":"http://127.0.0.1/solr", [junit4] 2> "node_name":"node2", [junit4] 2> "collection":"collection1", [junit4] 2> "core":"core2", [junit4] 2> "roles":"", [junit4] 2> "state":"active"} current state version: 2 [junit4] 2> 1585824 INFO (OverseerStateUpdate-95424740062724099-127.0.0.1:56594_solr-n_0000000000) [ ] o.a.s.c.o.ReplicaMutator Update state numShards=null message={ [junit4] 2> "operation":"state", [junit4] 2> "base_url":"http://127.0.0.1/solr", [junit4] 2> "node_name":"node2", [junit4] 2> "collection":"collection1", [junit4] 2> "core":"core2", [junit4] 2> "roles":"", [junit4] 2> "state":"active"} [junit4] 2> 1585825 INFO (OverseerStateUpdate-95424740062724099-127.0.0.1:56594_solr-n_0000000000) [ ] o.a.s.c.o.ReplicaMutator node=core_node6 is already registered [junit4] 2> 1585825 INFO (OverseerStateUpdate-95424740062724099-127.0.0.1:56594_solr-n_0000000000) [ ] o.a.s.c.o.ReplicaMutator shard=shard2 is already registered [junit4] 2> 1585827 INFO (OverseerStateUpdate-95424740062724099-127.0.0.1:56594_solr-n_0000000000) [ ] o.a.s.c.Overseer processMessage: queueSize: 6, message = { [junit4] 2> "operation":"state", [junit4] 2> "base_url":"http://127.0.0.1/solr", [junit4] 2> "node_name":"node3", [junit4] 2> "collection":"collection1", [junit4] 2> "core":"core3", [junit4] 2> "roles":"", [junit4] 2> "state":"active"} current state version: 2 [junit4] 2> 1585828 INFO (OverseerStateUpdate-95424740062724099-127.0.0.1:56594_solr-n_0000000000) [ ] o.a.s.c.o.ReplicaMutator Update state numShards=null message={ [junit4] 2> "operati [...truncated too long message...] FO (zkCallback-2154-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json], has occurred - updating... (live nodes size: [1]) [junit4] 2> 1684931 INFO (zkCallback-2147-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json], has occurred - updating... (live nodes size: [1]) [junit4] 2> 1684934 INFO (TEST-OverseerTest.testDoubleAssignment-seed#[F5E73FF24E2B6B9E]) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (1) [junit4] 2> 1684936 INFO (zkCallback-2154-thread-1) [ ] o.a.s.c.c.ZkStateReader A live node change: [WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes], has occurred - updating... (live nodes size: [1]) [junit4] 2> 1684936 INFO (zkCallback-2147-thread-1) [ ] o.a.s.c.c.ZkStateReader A live node change: [WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes], has occurred - updating... (live nodes size: [1]) [junit4] 2> 1684937 INFO (zkCallback-2147-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (0) [junit4] 2> 1684937 INFO (zkCallback-2154-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (0) [junit4] 2> 1684938 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 0x153044d277c0005, likely client has closed socket [junit4] 2> at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:228) [junit4] 2> at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208) [junit4] 2> at java.lang.Thread.run(Thread.java:745) [junit4] 2> 1684943 INFO (TEST-OverseerTest.testDoubleAssignment-seed#[F5E73FF24E2B6B9E]) [ ] o.a.s.c.ZkTestServer connecting to 127.0.0.1:52174 52174 [junit4] 2> 1684969 INFO (Thread-4196) [ ] o.a.s.c.ZkTestServer connecting to 127.0.0.1:52174 52174 [junit4] 2> 1684971 WARN (Thread-4196) [ ] o.a.s.c.ZkTestServer Watch limit violations: [junit4] 2> Maximum concurrent create/delete watches above limit: [junit4] 2> [junit4] 2> 4 /solr/aliases.json [junit4] 2> [junit4] 2> Maximum concurrent data watches above limit: [junit4] 2> [junit4] 2> 4 /solr/clusterstate.json [junit4] 2> [junit4] 2> Maximum concurrent children watches above limit: [junit4] 2> [junit4] 2> 4 /solr/live_nodes [junit4] 2> 4 /solr/collections [junit4] 2> [junit4] 2> 1684972 INFO (TEST-OverseerTest.testDoubleAssignment-seed#[F5E73FF24E2B6B9E]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testDoubleAssignment [junit4] 2> 1684972 INFO (TEST-OverseerTest.testDoubleAssignment-seed#[F5E73FF24E2B6B9E]) [ ] o.a.s.c.Overseer Overseer (id=95424746526343172-127.0.0.1:52174_solr-n_0000000000) closing [junit4] 2> 1684972 INFO (OverseerStateUpdate-95424746526343172-127.0.0.1:52174_solr-n_0000000000) [ ] o.a.s.c.Overseer Overseer Loop exiting : 127.0.0.1:52174_solr [junit4] 2> 1684974 ERROR (OverseerExitThread) [ ] o.a.s.c.Overseer could not read the data [junit4] 2> org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /overseer_elect/leader [junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:127) [junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:51) [junit4] 2> at org.apache.zookeeper.ZooKeeper.getData(ZooKeeper.java:1155) [junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:353) [junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:350) [junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:60) [junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.getData(SolrZkClient.java:350) [junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.checkIfIamStillLeader(Overseer.java:308) [junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.access$300(Overseer.java:89) [junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater$2.run(Overseer.java:267) [junit4] 2> 1687976 INFO (SUITE-OverseerTest-seed#[F5E73FF24E2B6B9E]-worker) [ ] o.a.s.SolrTestCaseJ4 ###deleteCore [junit4] 2> NOTE: leaving temporary files on disk at: /export/home/jenkins/workspace/Lucene-Solr-trunk-Solaris/solr/build/solr-core/test/J0/temp/solr.cloud.OverseerTest_F5E73FF24E2B6B9E-001 [junit4] 2> NOTE: test params are: codec=Lucene60, sim=RandomSimilarity(queryNorm=true,coord=yes): {}, locale=es-BO, timezone=Europe/Athens [junit4] 2> NOTE: SunOS 5.11 amd64/Oracle Corporation 1.8.0_72 (64-bit)/cpus=3,threads=1,free=216704944,total=518979584 [junit4] 2> NOTE: All tests run in this JVM: [SuggestComponentContextFilterQueryTest, DistributedFacetPivotSmallAdvancedTest, TestReplicationHandlerBackup, DisMaxRequestHandlerTest, TestCodecSupport, DistributedFacetPivotLargeTest, TestMissingGroups, TestManagedSchemaFieldResource, TestDFISimilarityFactory, TestFieldTypeResource, TestSort, TestLFUCache, SharedFSAutoReplicaFailoverTest, UpdateParamsTest, TestJmxMonitoredMap, TestStressLucene, PeerSyncTest, DistribCursorPagingTest, AddSchemaFieldsUpdateProcessorFactoryTest, SliceStateTest, StatelessScriptUpdateProcessorFactoryTest, TestLRUCache, RuleEngineTest, SuggesterFSTTest, CloneFieldUpdateProcessorFactoryTest, TestFieldResource, RegexBoostProcessorTest, TestHighlightDedupGrouping, FullHLLTest, DistributedQueryElevationComponentTest, TestExactStatsCache, HdfsRecoverLeaseTest, TestFastLRUCache, TestPartialUpdateDeduplication, HdfsUnloadDistributedZkTest, DeleteShardTest, SimpleCollectionCreateDeleteTest, TestPhraseSuggestions, PolyFieldTest, TestSolrConfigHandlerCloud, TestAuthorizationFramework, TestInitQParser, TestRandomDVFaceting, BlockJoinFacetDistribTest, TestCollapseQParserPlugin, SpatialFilterTest, TestSolrCloudWithKerberosAlt, DocValuesMissingTest, TestLazyCores, TestRuleBasedAuthorizationPlugin, ChaosMonkeyNothingIsSafeTest, DocumentBuilderTest, TestMergePolicyConfig, PrimUtilsTest, CoreAdminCreateDiscoverTest, DistributedSpellCheckComponentTest, SaslZkACLProviderTest, TestSolrQueryParserDefaultOperatorResource, SpatialRPTFieldTypeTest, TestAnalyzedSuggestions, HdfsRestartWhileUpdatingTest, TimeZoneUtilsTest, TestSolrDeletionPolicy1, TestDocumentBuilder, HdfsChaosMonkeyNothingIsSafeTest, TestRestoreCore, IndexSchemaTest, TestLMDirichletSimilarityFactory, TestRemoteStreaming, CircularListTest, TestCloudInspectUtil, DistributedDebugComponentTest, TestSearchPerf, TestReloadDeadlock, TestLuceneMatchVersion, DistributedFacetPivotWhiteBoxTest, TestSweetSpotSimilarityFactory, ActionThrottleTest, MBeansHandlerTest, TestSchemaVersionResource, TestCryptoKeys, TestCustomSort, TestFileDictionaryLookup, ClusterStateTest, CollectionStateFormat2Test, TestRestManager, JsonLoaderTest, SchemaVersionSpecificBehaviorTest, TestComponentsName, TestPseudoReturnFields, AsyncMigrateRouteKeyTest, TestUpdate, DocumentAnalysisRequestHandlerTest, TestImplicitCoreProperties, TestDistributedStatsComponentCardinality, TestBlobHandler, TestLeaderElectionZkExpiry, ClusterStateUpdateTest, TestCollectionAPI, TestConfig, SolrIndexConfigTest, TestIBSimilarityFactory, ZkCLITest, DistribJoinFromCollectionTest, HighlighterTest, RecoveryAfterSoftCommitTest, DeleteLastCustomShardedReplicaTest, TestDefaultSearchFieldResource, TestReplicaProperties, SolrRequestParserTest, TestScoreJoinQPNoScore, PreAnalyzedFieldTest, TestPostingsSolrHighlighter, TestConfigSets, ScriptEngineTest, TermsComponentTest, HttpPartitionTest, TestOverriddenPrefixQueryForCustomFieldType, AnalysisAfterCoreReloadTest, HLLUtilTest, MigrateRouteKeyTest, BadComponentTest, CdcrUpdateLogTest, RollingRestartTest, RecoveryZkTest, TestManagedSynonymFilterFactory, TestManagedSchema, HdfsCollectionsAPIDistributedZkTest, FacetPivotSmallTest, TestFaceting, ExitableDirectoryReaderTest, SolrXmlInZkTest, TestQuerySenderNoQuery, SOLR749Test, TestSortByMinMaxFunction, ReturnFieldsTest, UnloadDistributedZkTest, DistributedQueryComponentOptimizationTest, BasicDistributedZkTest, ChaosMonkeySafeLeaderTest, BasicDistributedZk2Test, SyncSliceTest, OpenCloseCoreStressTest, OverseerTest] [junit4] Completed [296/579 (1!)] on J0 in 107.01s, 13 tests, 1 error, 1 skipped <<< FAILURES! [...truncated 911 lines...] BUILD FAILED /export/home/jenkins/workspace/Lucene-Solr-trunk-Solaris/build.xml:740: The following error occurred while executing this line: /export/home/jenkins/workspace/Lucene-Solr-trunk-Solaris/build.xml:684: The following error occurred while executing this line: /export/home/jenkins/workspace/Lucene-Solr-trunk-Solaris/build.xml:59: The following error occurred while executing this line: /export/home/jenkins/workspace/Lucene-Solr-trunk-Solaris/solr/build.xml:233: The following error occurred while executing this line: /export/home/jenkins/workspace/Lucene-Solr-trunk-Solaris/solr/common-build.xml:524: The following error occurred while executing this line: /export/home/jenkins/workspace/Lucene-Solr-trunk-Solaris/lucene/common-build.xml:1457: The following error occurred while executing this line: /export/home/jenkins/workspace/Lucene-Solr-trunk-Solaris/lucene/common-build.xml:1014: There were test failures: 579 suites (8 ignored), 2331 tests, 1 error, 88 ignored (72 assumptions) [seed: F5E73FF24E2B6B9E] Total time: 69 minutes 40 seconds Build step 'Invoke Ant' marked build as failure Archiving artifacts [WARNINGS] Skipping publisher since build result is FAILURE Recording test results Email was triggered for: Failure - Any Sending email for trigger: Failure - Any
--------------------------------------------------------------------- To unsubscribe, e-mail: dev-unsubscr...@lucene.apache.org For additional commands, e-mail: dev-h...@lucene.apache.org