Build: http://jenkins.thetaphi.de/job/Lucene-Solr-4.10-Linux/67/ Java: 64bit/jdk1.7.0_67 -XX:-UseCompressedOops -XX:+UseParallelGC (asserts: true)
1 tests failed. FAILED: org.apache.solr.cloud.OverseerTest.testOverseerFailure 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([5521FA015B1A02AA:512975F249BFED8B]:0) at org.apache.solr.cloud.ShardLeaderElectionContextBase.runLeaderProcess(ElectionContext.java:150) at org.apache.solr.cloud.LeaderElector.runIamLeaderProcess(LeaderElector.java:163) at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:125) at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:155) at org.apache.solr.cloud.LeaderElector.joinElection(LeaderElector.java:314) at org.apache.solr.cloud.LeaderElector.joinElection(LeaderElector.java:221) at org.apache.solr.cloud.OverseerTest$MockZKController.publishState(OverseerTest.java:157) at org.apache.solr.cloud.OverseerTest.testOverseerFailure(OverseerTest.java:662) at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.lang.reflect.Method.invoke(Method.java:606) at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1618) at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:827) at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:863) at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:877) at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53) at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:50) at org.apache.lucene.util.TestRuleFieldCacheSanity$1.evaluate(TestRuleFieldCacheSanity.java:51) at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46) at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55) at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:49) at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:65) at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48) at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:365) at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:798) at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:458) at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:836) at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:738) at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:772) at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:783) at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53) at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46) at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:42) at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55) at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39) at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39) 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:54) at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48) at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:65) at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:55) at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:365) at java.lang.Thread.run(Thread.java:745) Caused by: org.apache.solr.common.SolrException: org.apache.zookeeper.KeeperException$NodeExistsException: KeeperErrorCode = NodeExists for /collections/collection1/leaders/shard1 at org.apache.solr.common.util.RetryUtil.retryOnThrowable(RetryUtil.java:40) at org.apache.solr.cloud.ShardLeaderElectionContextBase.runLeaderProcess(ElectionContext.java:137) ... 48 more Caused by: org.apache.zookeeper.KeeperException$NodeExistsException: KeeperErrorCode = NodeExists for /collections/collection1/leaders/shard1 at org.apache.zookeeper.KeeperException.create(KeeperException.java:119) at org.apache.zookeeper.KeeperException.create(KeeperException.java:51) at org.apache.zookeeper.ZooKeeper.create(ZooKeeper.java:783) at org.apache.solr.common.cloud.SolrZkClient$11.execute(SolrZkClient.java:462) at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:74) at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:459) at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:416) at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:403) at org.apache.solr.cloud.ShardLeaderElectionContextBase$1.execute(ElectionContext.java:142) at org.apache.solr.common.util.RetryUtil.retryOnThrowable(RetryUtil.java:34) ... 49 more Build Log: [...truncated 11631 lines...] [junit4] Suite: org.apache.solr.cloud.OverseerTest [junit4] 2> Creating dataDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.10-Linux/solr/build/solr-core/test/J1/./solr.cloud.OverseerTest-5521FA015B1A02AA-001/init-core-data-001 [junit4] 2> 1620465 T4352 oas.SolrTestCaseJ4.buildSSLConfig Randomized ssl (false) and clientAuth (false) [junit4] 2> 1620465 T4352 oas.SolrTestCaseJ4.initCore ####initCore [junit4] 2> 1620465 T4352 oas.SolrTestCaseJ4.initCore ####initCore end [junit4] 2> 1620468 T4352 oas.SolrTestCaseJ4.setUp ###Starting testOverseerFailure [junit4] 2> 1620468 T4352 oasc.ZkTestServer.run STARTING ZK TEST SERVER [junit4] 1> client port:0.0.0.0/0.0.0.0:0 [junit4] 2> 1620469 T4353 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server [junit4] 2> 1620569 T4352 oasc.ZkTestServer.run start zk server on port:32998 [junit4] 2> 1620570 T4352 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper [junit4] 2> 1620575 T4359 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@39bebd5f name:ZooKeeperConnection Watcher:127.0.0.1:32998 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4] 2> 1620575 T4352 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper [junit4] 2> 1620579 T4352 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper [junit4] 2> 1620581 T4361 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@36b98a2f name:ZooKeeperConnection Watcher:127.0.0.1:32998 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4] 2> 1620582 T4352 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper [junit4] 2> 1620582 T4352 oascc.SolrZkClient.makePath makePath: /solr [junit4] 2> 1620589 T4352 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper [junit4] 2> 1620591 T4363 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@4fbb50df name:ZooKeeperConnection Watcher:127.0.0.1:32998/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4] 2> 1620591 T4352 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper [junit4] 2> 1620591 T4352 oascc.SolrZkClient.makePath makePath: /live_nodes [junit4] 2> 1620595 T4352 oascc.SolrZkClient.makePath makePath: /clusterstate.json [junit4] 2> 1620598 T4352 oascc.SolrZkClient.makePath makePath: /aliases.json [junit4] 2> 1620600 T4352 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... [junit4] 2> 1620605 T4352 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper [junit4] 2> 1620607 T4365 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@339416c9 name:ZooKeeperConnection Watcher:127.0.0.1:32998/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4] 2> 1620607 T4352 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper [junit4] 2> 1620609 T4352 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... [junit4] 2> 1620613 T4352 oascc.SolrZkClient.makePath makePath: /live_nodes/node1 [junit4] 2> 1620617 T4352 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper [junit4] 2> 1620619 T4369 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@74e0321d name:ZooKeeperConnection Watcher:127.0.0.1:32998/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4] 2> 1620619 T4352 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper [junit4] 2> 1620620 T4352 oasu.UpdateShardHandler.<init> Creating UpdateShardHandler HTTP client with params: retry=false [junit4] 2> 1620622 T4352 oascc.SolrZkClient.makePath makePath: /overseer_elect [junit4] 2> 1620624 T4352 oascc.SolrZkClient.makePath makePath: /overseer_elect/election [junit4] 2> 1620627 T4352 oasc.Overseer.close Overseer (id=null) closing [junit4] 2> 1620629 T4352 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:32998_solr [junit4] 2> 1620630 T4352 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader [junit4] 2> 1620632 T4352 oasc.Overseer.start Overseer (id=92765866147905540-127.0.0.1:32998_solr-n_0000000000) starting [junit4] 2> 1620633 T4352 oascc.SolrZkClient.makePath makePath: /overseer/queue [junit4] 2> 1620636 T4352 oascc.SolrZkClient.makePath makePath: /overseer/queue-work [junit4] 2> 1620639 T4352 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-failure [junit4] 2> 1620643 T4352 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-running [junit4] 2> 1620647 T4352 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-completed [junit4] 2> 1620651 T4352 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work [junit4] 2> 1620656 T4352 oasc.OverseerAutoReplicaFailoverThread.<init> Starting OverseerAutoReplicaFailoverThread autoReplicaFailoverWorkLoopDelay=10000 autoReplicaFailoverWaitAfterExpiration=30000 autoReplicaFailoverBadNodeExpiration=60000 [junit4] 2> 1620657 T4371 oasc.OverseerCollectionProcessor.run Process current queue of collection creations [junit4] 2> 1620658 T4370 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue [junit4] 2> 1621659 T4373 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged [junit4] 2> 1621661 T4370 oasc.Overseer$ClusterStateUpdater.updateState 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> 1621662 T4370 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1] [junit4] 2> 1621662 T4370 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1 [junit4] 2> 1621664 T4367 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1) [junit4] 2> 1621664 T4366 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1) [junit4] 2> 1622159 T4352 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election [junit4] 2> 1622165 T4352 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1 [junit4] 2> 1622168 T4373 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged [junit4] 2> 1622169 T4352 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election [junit4] 2> 1622170 T4370 oasc.Overseer$ClusterStateUpdater.updateState 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> 1622170 T4370 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered [junit4] 2> 1622171 T4373 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged [junit4] 2> 1622172 T4366 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1) [junit4] 2> 1622172 T4367 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1) [junit4] 2> 1622660 T4371 oasc.OverseerCollectionProcessor.amILeader 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$8.execute(SolrZkClient.java:307) [junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$8.execute(SolrZkClient.java:304) [junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:74) [junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.getData(SolrZkClient.java:304) [junit4] 2> at org.apache.solr.cloud.OverseerCollectionProcessor.amILeader(OverseerCollectionProcessor.java:514) [junit4] 2> at org.apache.solr.cloud.OverseerCollectionProcessor.run(OverseerCollectionProcessor.java:272) [junit4] 2> at java.lang.Thread.run(Thread.java:745) [junit4] 2> [junit4] 2> 1622660 T4371 oasc.OverseerCollectionProcessor.amILeader According to ZK I (id=92765866147905540-127.0.0.1:32998_solr-n_0000000000) am no longer a leader. [junit4] 2> 1623226 T4352 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election [junit4] 2> 1623230 T4352 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper [junit4] 2> 1623231 T4375 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@24384e8c name:ZooKeeperConnection Watcher:127.0.0.1:32998/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4] 2> 1623231 T4352 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper [junit4] 2> 1623231 T4352 oasc.Overseer.close Overseer (id=92765866147905540-127.0.0.1:32998_solr-n_0000000000) closing [junit4] 2> 1623232 T4370 oasc.Overseer$ClusterStateUpdater.run Overseer Loop exiting : 127.0.0.1:32998_solr [junit4] 2> 1623233 T4352 oasu.UpdateShardHandler.<init> Creating UpdateShardHandler HTTP client with params: retry=false [junit4] 2> 1623234 T4376 oasc.Overseer$ClusterStateUpdater.checkIfIamStillLeader ERROR could not read the data 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$8.execute(SolrZkClient.java:307) [junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$8.execute(SolrZkClient.java:304) [junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:74) [junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.getData(SolrZkClient.java:304) [junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.checkIfIamStillLeader(Overseer.java:320) [junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.access$300(Overseer.java:89) [junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater$1.run(Overseer.java:292) [junit4] 2> [junit4] 2> 1623235 T4352 oasc.Overseer.close Overseer (id=null) closing [junit4] 2> 1623236 T4352 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:32998_solr [junit4] 2> 1623236 T4352 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader [junit4] 2> 1623237 T4352 oasc.Overseer.start Overseer (id=92765866147905541-127.0.0.1:32998_solr-n_0000000001) starting [junit4] 2> 1623242 T4352 oasc.OverseerAutoReplicaFailoverThread.<init> Starting OverseerAutoReplicaFailoverThread autoReplicaFailoverWorkLoopDelay=10000 autoReplicaFailoverWaitAfterExpiration=30000 autoReplicaFailoverBadNodeExpiration=60000 [junit4] 2> 1623243 T4378 oasc.OverseerCollectionProcessor.run Process current queue of collection creations [junit4] 2> 1623243 T4377 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue [junit4] 2> 1623245 T4377 oasc.Overseer$ClusterStateUpdater.updateState 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> 1623245 T4377 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered [junit4] 2> 1623246 T4380 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged [junit4] 2> 1623246 T4367 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1) [junit4] 2> 1623246 T4366 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1) [junit4] 2> 1623299 T4352 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election [junit4] 2> 1623299 T4380 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged [junit4] 2> 1623304 T4352 oasc.LeaderElector.checkIfIamLeader WARN Failed setting watch org.apache.zookeeper.KeeperException$NoNodeException: KeeperErrorCode = NoNode for /collections/collection1/leader_elect/shard1/election/92765866147905539-node1_core1-n_0000000002 [junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:111) [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$8.execute(SolrZkClient.java:307) [junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$8.execute(SolrZkClient.java:304) [junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:74) [junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.getData(SolrZkClient.java:304) [junit4] 2> at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:148) [junit4] 2> at org.apache.solr.cloud.LeaderElector.joinElection(LeaderElector.java:314) [junit4] 2> at org.apache.solr.cloud.LeaderElector.joinElection(LeaderElector.java:221) [junit4] 2> at org.apache.solr.cloud.OverseerTest$MockZKController.publishState(OverseerTest.java:157) [junit4] 2> at org.apache.solr.cloud.OverseerTest.testOverseerFailure(OverseerTest.java:662) [junit4] 2> at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) [junit4] 2> at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57) [junit4] 2> at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) [junit4] 2> at java.lang.reflect.Method.invoke(Method.java:606) [junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1618) [junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:827) [junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:863) [junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:877) [junit4] 2> at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53) [junit4] 2> at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:50) [junit4] 2> at org.apache.lucene.util.TestRuleFieldCacheSanity$1.evaluate(TestRuleFieldCacheSanity.java:51) [junit4] 2> at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46) [junit4] 2> at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55) [junit4] 2> at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:49) [junit4] 2> at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:65) [junit4] 2> at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48) [junit4] 2> at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) [junit4] 2> at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:365) [junit4] 2> at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:798) [junit4] 2> at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:458) [junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:836) [junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:738) [junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:772) [junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:783) [junit4] 2> at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) [junit4] 2> at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53) [junit4] 2> at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46) [junit4] 2> at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:42) [junit4] 2> at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55) [junit4] 2> at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39) [junit4] 2> at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39) [junit4] 2> at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) [junit4] 2> at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) [junit4] 2> at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) [junit4] 2> at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:54) [junit4] 2> at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48) [junit4] 2> at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:65) [junit4] 2> at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:55) [junit4] 2> at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) [junit4] 2> at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:365) [junit4] 2> at java.lang.Thread.run(Thread.java:745) [junit4] 2> [junit4] 2> 1623306 T4377 oasc.SolrException.log ERROR Problem cleaning up collection in zk:collection1:org.apache.zookeeper.KeeperException$NotEmptyException: KeeperErrorCode = Directory not empty for /collections/collection1/leader_elect/shard1/election [junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:125) [junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:51) [junit4] 2> at org.apache.zookeeper.ZooKeeper.delete(ZooKeeper.java:873) [junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$2.execute(SolrZkClient.java:189) [junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$2.execute(SolrZkClient.java:186) [junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:74) [junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.delete(SolrZkClient.java:186) [junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.clean(SolrZkClient.java:670) [junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.clean(SolrZkClient.java:665) [junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.clean(SolrZkClient.java:665) [junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.clean(SolrZkClient.java:665) [junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.removeCore(Overseer.java:1104) [junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.processMessage(Overseer.java:362) [junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.run(Overseer.java:244) [junit4] 2> at java.lang.Thread.run(Thread.java:745) [junit4] 2> [junit4] 2> 1623306 T4381 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1 [junit4] 2> 1623305 T4366 oasc.LeaderElector.checkIfIamLeader WARN Our node is no longer in line to be leader [junit4] 2> 1623306 T4352 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1 [junit4] 2> 1623309 T4380 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged [junit4] 2> 1623310 T4377 oasc.Overseer$ClusterStateUpdater.setShardLeader ERROR Could not mark shard leader for non existing collection:collection1 [junit4] 2> 1623413 T4367 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1) [junit4] 2> 1623413 T4381 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1) [junit4] 2> 1624309 T4352 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1 [junit4] 2> 1625312 T4352 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1 [junit4] 2> 1626314 T4352 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1 [junit4] 2> 1627316 T4352 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1 [junit4] 2> 1628320 T4352 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1 [junit4] 2> 1629322 T4352 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1 [junit4] 2> 1630326 T4352 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1 [junit4] 2> 1631328 T4352 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1 [junit4] 2> 1632331 T4352 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1 [junit4] 2> 1633333 T4352 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1 [junit4] 2> 1634336 T4352 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1 [junit4] 2> 1635338 T4352 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1 [junit4] 2> 1636340 T4352 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1 [junit4] 2> 1637342 T4352 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1 [junit4] 2> 1638345 T4352 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1 [junit4] 2> 1638352 T4352 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:32998 32998 [junit4] 2> 1639026 T4353 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:32998 32998 [junit4] 2> 1639028 T4352 oas.SolrTestCaseJ4.tearDown ###Ending testOverseerFailure [junit4] 2> 1639028 T4352 oasc.Overseer.close Overseer (id=92765866147905541-127.0.0.1:32998_solr-n_0000000001) closing [junit4] 2> 1639028 T4377 oasc.Overseer$ClusterStateUpdater.run Overseer Loop exiting : 127.0.0.1:32998_solr [junit4] 2> 1639030 T4382 oasc.Overseer$ClusterStateUpdater.checkIfIamStillLeader ERROR could not read the data 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$8.execute(SolrZkClient.java:307) [junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$8.execute(SolrZkClient.java:304) [junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:74) [junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.getData(SolrZkClient.java:304) [junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.checkIfIamStillLeader(Overseer.java:320) [junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.access$300(Overseer.java:89) [junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater$1.run(Overseer.java:292) [junit4] 2> [junit4] 2> NOTE: reproduce with: ant test -Dtestcase=OverseerTest -Dtests.method=testOverseerFailure -Dtests.seed=5521FA015B1A02AA -Dtests.multiplier=3 -Dtests.slow=true -Dtests.locale=es_PR -Dtests.timezone=Europe/Tiraspol -Dtests.asserts=true -Dtests.file.encoding=US-ASCII [junit4] ERROR 18.6s J1 | OverseerTest.testOverseerFailure <<< [junit4] > Throwable #1: org.apache.solr.common.SolrException: Could not register as the leader because creating the ephemeral registration node in ZooKeeper failed [junit4] > at __randomizedtesting.SeedInfo.seed([5521FA015B1A02AA:512975F249BFED8B]:0) [junit4] > at org.apache.solr.cloud.ShardLeaderElectionContextBase.runLeaderProcess(ElectionContext.java:150) [junit4] > at org.apache.solr.cloud.LeaderElector.runIamLeaderProcess(LeaderElector.java:163) [junit4] > at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:125) [junit4] > at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:155) [junit4] > at org.apache.solr.cloud.LeaderElector.joinElection(LeaderElector.java:314) [junit4] > at org.apache.solr.cloud.LeaderElector.joinElection(LeaderElector.java:221) [junit4] > at org.apache.solr.cloud.OverseerTest$MockZKController.publishState(OverseerTest.java:157) [junit4] > at org.apache.solr.cloud.OverseerTest.testOverseerFailure(OverseerTest.java:662) [junit4] > at java.lang.Thread.run(Thread.java:745) [junit4] > Caused by: org.apache.solr.common.SolrException: org.apache.zookeeper.KeeperException$NodeExistsException: KeeperErrorCode = NodeExists for /collections/collection1/leaders/shard1 [junit4] > at org.apache.solr.common.util.RetryUtil.retryOnThrowable(RetryUtil.java:40) [junit4] > at org.apache.solr.cloud.ShardLeaderElectionContextBase.runLeaderProcess(ElectionContext.java:137) [junit4] > ... 48 more [junit4] > Caused by: org.apache.zookeeper.KeeperException$NodeExistsException: KeeperErrorCode = NodeExists for /collections/collection1/leaders/shard1 [junit4] > at org.apache.zookeeper.KeeperException.create(KeeperException.java:119) [junit4] > at org.apache.zookeeper.KeeperException.create(KeeperException.java:51) [junit4] > at org.apache.zookeeper.ZooKeeper.create(ZooKeeper.java:783) [junit4] > at org.apache.solr.common.cloud.SolrZkClient$11.execute(SolrZkClient.java:462) [junit4] > at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:74) [junit4] > at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:459) [junit4] > at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:416) [junit4] > at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:403) [junit4] > at org.apache.solr.cloud.ShardLeaderElectionContextBase$1.execute(ElectionContext.java:142) [junit4] > at org.apache.solr.common.util.RetryUtil.retryOnThrowable(RetryUtil.java:34) [junit4] > ... 49 more [junit4] 2> 1639043 T4352 oas.SolrTestCaseJ4.setUp ###Starting testStateChange [junit4] 2> 1639044 T4352 oasc.ZkTestServer.run STARTING ZK TEST SERVER [junit4] 1> client port:0.0.0.0/0.0.0.0:0 [junit4] 2> 1639045 T4383 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server [junit4] 2> 1639144 T4352 oasc.ZkTestServer.run start zk server on port:44886 [junit4] 2> 1639145 T4352 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper [junit4] 2> 1639148 T4389 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@2a59f3ee name:ZooKeeperConnection Watcher:127.0.0.1:44886/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4] 2> 1639148 T4352 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper [junit4] 2> 1639149 T4352 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper [junit4] 2> 1639150 T4391 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@32ebfc0a name:ZooKeeperConnection Watcher:127.0.0.1:44886 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4] 2> 1639150 T4352 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper [junit4] 2> 1639152 T4352 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper [junit4] 2> 1639153 T4393 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@4ceb9b64 name:ZooKeeperConnection Watcher:127.0.0.1:44886 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4] 2> 1639153 T4352 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper [junit4] 2> 1639154 T4352 oascc.SolrZkClient.makePath makePath: /solr [junit4] 2> 1639157 T4352 oascc.SolrZkClient.makePath makePath: /live_nodes [junit4] 2> 1639159 T4352 oascc.SolrZkClient.makePath makePath: /clusterstate.json [junit4] 2> 1639161 T4352 oascc.SolrZkClient.makePath makePath: /aliases.json [junit4] 2> 1639162 T4352 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... [junit4] 2> 1639163 T4352 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper [junit4] 2> 1639164 T4395 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@19043c85 name:ZooKeeperConnection Watcher:127.0.0.1:44886/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4] 2> 1639164 T4352 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper [junit4] 2> 1639165 T4352 oasu.UpdateShardHandler.<init> Creating UpdateShardHandler HTTP client with params: retry=false [junit4] 2> 1639166 T4352 oascc.SolrZkClient.makePath makePath: /overseer_elect [junit4] 2> 1639167 T4352 oascc.SolrZkClient.makePath makePath: /overseer_elect/election [junit4] 2> 1639168 T4352 oasc.Overseer.close Overseer (id=null) closing [junit4] 2> 1639169 T4352 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:44886_solr [junit4] 2> 1639169 T4352 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader [junit4] 2> 1639170 T4352 oasc.Overseer.start Overseer (id=92765867365302275-127.0.0.1:44886_solr-n_0000000000) starting [junit4] 2> 1639171 T4352 oascc.SolrZkClient.makePath makePath: /overseer/queue [junit4] 2> 1639172 T4352 oascc.SolrZkClient.makePath makePath: /overseer/queue-work [junit4] 2> 1639174 T4352 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-failure [junit4] 2> 1639175 T4352 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-running [junit4] 2> 1639176 T4352 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-completed [junit4] 2> 1639178 T4352 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work [junit4] 2> 1639180 T4352 oasc.OverseerAutoReplicaFailoverThread.<init> Starting OverseerAutoReplicaFailoverThread autoReplicaFailoverWorkLoopDelay=10000 autoReplicaFailoverWaitAfterExpiration=30000 autoReplicaFailoverBadNodeExpiration=60000 [junit4] 2> 1639181 T4397 oasc.OverseerCollectionProcessor.run Process current queue of collection creations [junit4] 2> 1639181 T4396 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue [junit4] 2> 1639183 T4396 oasc.Overseer$ClusterStateUpdater.updateState 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":"recovering"} [junit4] 2> 1639183 T4396 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1 [junit4] 2> 1639184 T4399 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged [junit4] 2> 1639184 T4400 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 0) [junit4] 2> 1639234 T4399 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged [junit4] 2> 1639235 T4396 oasc.Overseer$ClusterStateUpdater.updateState 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> 1639236 T4396 oasc.Overseer$ClusterStateUpdater.updateState node=core_node1 is already registered [junit4] 2> 1639236 T4396 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered [junit4] 2> 1639339 T4400 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 0) [junit4] 2> 1639387 T4352 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:44886 44886 [junit4] 2> 1639955 T4383 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:44886 44886 [junit4] 2> 1639956 T4352 oas.SolrTestCaseJ4.tearDown ###Ending testStateChange [junit4] 2> 1639956 T4352 oasc.Overseer.close Overseer (id=92765867365302275-127.0.0.1:44886_solr-n_0000000000) closing [junit4] 2> 1639957 T4396 oasc.Overseer$ClusterStateUpdater.run Overseer Loop exiting : 127.0.0.1:44886_solr [junit4] 2> 1639959 T4401 oasc.Overseer$ClusterStateUpdater.checkIfIamStillLeader ERROR could not read the data 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$8.execute(SolrZkClient.java:307) [junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$8.execute(SolrZkClient.java:304) [junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:74) [junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.getData(SolrZkClient.java:304) [junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.checkIfIamStillLeader(Overseer.java:320) [junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.access$300(Overseer.java:89) [junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater$1.run(Overseer.java:292) [junit4] 2> [junit4] 2> 1639966 T4352 oas.SolrTestCaseJ4.setUp ###Starting testShardAssignment [junit4] 2> 1639967 T4352 oasc.ZkTestServer.run STARTING ZK TEST SERVER [junit4] 1> client port:0.0.0.0/0.0.0.0:0 [junit4] 2> 1639968 T4402 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server [junit4] 2> 1640067 T4352 oasc.ZkTestServer.run start zk server on port:40082 [junit4] 2> 1640069 T4352 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper [junit4] 2> 1640071 T4408 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@4becc9ef name:ZooKeeperConnection Watcher:127.0.0.1:40082 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4] 2> 1640071 T4352 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper [junit4] 2> 1640073 T4352 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper [junit4] 2> 1640074 T4410 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@4a26d9a7 name:ZooKeeperConnection Watcher:127.0.0.1:40082 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4] 2> 1640074 T4352 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper [junit4] 2> 1640075 T4352 oascc.SolrZkClient.makePath makePath: /solr [junit4] 2> 1640079 T4352 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper [junit4] 2> 1640080 T4412 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@3dd5dc8b name:ZooKeeperConnection Watcher:127.0.0.1:40082/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4] 2> 1640080 T4352 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper [junit4] 2> 1640080 T4352 oascc.SolrZkClient.makePath makePath: /live_nodes [junit4] 2> 1640083 T4352 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper [junit4] 2> 1640084 T4414 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@26686864 name:ZooKeeperConnection Watcher:127.0.0.1:40082/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4] 2> 1640084 T4352 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper [junit4] 2> 1640085 T4352 oasu.UpdateShardHandler.<init> Creating UpdateShardHandler HTTP client with params: retry=false [junit4] 2> 1640087 T4352 oascc.SolrZkClient.makePath makePath: /overseer_elect [junit4] 2> 1640090 T4352 oascc.SolrZkClient.makePath makePath: /overseer_elect/election [junit4] 2> 1640091 T4352 oasc.Overseer.close Overseer (id=null) closing [junit4] 2> 1640093 T4352 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:40082_solr [junit4] 2> 1640093 T4352 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader [junit4] 2> 1640095 T4352 oasc.Overseer.start Overseer (id=92765867425857539-127.0.0.1:40082_solr-n_0000000000) starting [junit4] 2> 1640097 T4352 oascc.SolrZkClient.makePath makePath: /overseer/queue [junit4] 2> 1640100 T4352 oascc.SolrZkClient.makePath makePath: /overseer/queue-work [junit4] 2> 1640103 T4352 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-failure [junit4] 2> 1640105 T4352 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-running [junit4] 2> 1640108 T4352 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-completed [junit4] 2> 1640111 T4352 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work [junit4] 2> 1640114 T4352 oasc.OverseerAutoReplicaFailoverThread.<init> Starting OverseerAutoReplicaFailoverThread autoReplicaFailoverWorkLoopDelay=10000 autoReplicaFailoverWaitAfterExpiration=30000 autoReplicaFailoverBadNodeExpiration=60000 [junit4] 2> 1640115 T4416 oasc.OverseerCollectionProcessor.run Process current queue of collection creations [junit4] 2> 1640116 T4352 oascc.SolrZkClient.makePath makePath: /clusterstate.json [junit4] 2> 1640116 T4415 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue [junit4] 2> 1640117 T4352 oascc.SolrZkClient.makePath makePath: /aliases.json [junit4] 2> 1640118 T4352 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... [junit4] 2> 1640119 T4352 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper [junit4] 2> 1640120 T4419 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@522c03b7 name:ZooKeeperConnection Watcher:127.0.0.1:40082/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4] 2> 1640120 T4352 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper [junit4] 2> 1640122 T4352 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... [junit4] 2> 1640123 T4352 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1 [junit4] 2> 1640127 T4422 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged [junit4] 2> 1640128 T4415 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={ [junit4] 2> "operation":"state", [junit4] 2> "state":"active", [junit4] 2> "node_name":"127.0.0.1", [junit4] 2> "core":"core1", [junit4] 2> "core_node_name":"node1", [junit4] 2> "collection":"collection1", [junit4] 2> "numShards":"3", [junit4] 2> "base_url":"http://127.0.0.1/solr/"} [junit4] 2> 1640128 T4415 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1, shard2, shard3] [junit4] 2> 1640128 T4415 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1 [junit4] 2> 1640131 T4421 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1) [junit4] 2> 1640131 T4420 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1) [junit4] 2> 1640627 T4352 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election [junit4] 2> 1640632 T4352 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1 [junit4] 2> 1640634 T4422 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged [junit4] 2> 1640636 T4415 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={ [junit4] 2> "operation":"state", [junit4] 2> "state":"active", [junit4] 2> "node_name":"127.0.0.1", [junit4] 2> "core":"core2", [junit4] 2> "core_node_name":"node2", [junit4] 2> "collection":"collection1", [junit4] 2> "numShards":"3", [junit4] 2> "base_url":"http://127.0.0.1/solr/"} [junit4] 2> 1640637 T4415 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3 [junit4] 2> 1640637 T4415 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard3 [junit4] 2> 1640638 T4422 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged [junit4] 2> 1640638 T4421 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1) [junit4] 2> 1640639 T4420 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1) [junit4] 2> 1641135 T4352 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard3/election [junit4] 2> 1641140 T4352 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard3 [junit4] 2> 1641142 T4422 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged [junit4] 2> 1641145 T4415 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={ [junit4] 2> "operation":"state", [junit4] 2> "state":"active", [junit4] 2> "node_name":"127.0.0.1", [junit4] 2> "core":"core3", [junit4] 2> "core_node_name":"node3", [junit4] 2> "collection":"collection1", [junit4] 2> "numShards":"3", [junit4] 2> "base_url":"http://127.0.0.1/solr/"} [junit4] 2> 1641145 T4415 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3 [junit4] 2> 1641145 T4415 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard2 [junit4] 2> 1641146 T4422 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged [junit4] 2> 1641147 T4420 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1) [junit4] 2> 1641147 T4421 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1) [junit4] 2> 1641643 T4352 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard2/election [junit4] 2> 1641647 T4352 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard2 [junit4] 2> 1641649 T4422 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged [junit4] 2> 1641652 T4415 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={ [junit4] 2> "operation":"state", [junit4] 2> "state":"active", [junit4] 2> "node_name":"127.0.0.1", [junit4] 2> "core":"core4", [junit4] 2> "core_node_name":"node4", [junit4] 2> "collection":"collection1", [junit4] 2> "numShards":"3", [junit4] 2> "base_url":"http://127.0.0.1/solr/"} [junit4] 2> 1641652 T4415 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3 [junit4] 2> 1641652 T4415 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1 [junit4] 2> 1641653 T4422 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged [junit4] 2> 1641654 T4421 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1) [junit4] 2> 1641654 T4420 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1) [junit4] 2> 1642150 T4352 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election [junit4] 2> 1642155 T4422 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged [junit4] 2> 1642156 T4415 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={ [junit4] 2> "operation":"state", [junit4] 2> "state":"active", [junit4] 2> "node_name":"127.0.0.1", [junit4] 2> "core":"core5", [junit4] 2> "core_node_name":"node5", [junit4] 2> "collection":"collection1", [junit4] 2> "numShards":"3", [junit4] 2> "base_url":"http://127.0.0.1/solr/"} [junit4] 2> 1642156 T4415 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3 [junit4] 2> 1642156 T4415 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard3 [junit4] 2> 1642259 T4421 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1) [junit4] 2> 1642259 T4420 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1) [junit4] 2> 1642655 T4352 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard3/election [junit4] 2> 1642659 T4422 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged [junit4] 2> 1642660 T4415 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={ [junit4] 2> "operation":"state", [junit4] 2> "state":"active", [junit4] 2> "node_name":"127.0.0.1", [junit4] 2> "core":"core6", [junit4] 2> "core_node_name":"node6", [junit4] 2> "collection":"collection1", [junit4] 2> "numShards":"3", [junit4] 2> "base_url":"http://127.0.0.1/solr/"} [junit4] 2> 1642660 T4415 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3 [junit4] 2> 1642661 T4415 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard2 [junit4] 2> 1642763 T4420 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1) [junit4] 2> 1642763 T4421 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1) [junit4] 2> 1643159 T4352 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard2/election [junit4] 2> 1643164 T4423 oasc.LeaderElector$ElectionWatcher.process WARN org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /collections/collection1/leader_elect/shard1/election [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.getChildren(ZooKeeper.java:1472) [junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:290) [junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:287) [junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:74) [junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.getChildren(SolrZkClient.java:287) [junit4] 2> at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:94) [junit4] 2> at org.apache.solr.cloud.LeaderElector.access$200(LeaderElector.java:55) [junit4] 2> at org.apache.solr.cloud.LeaderElector$ElectionWatcher.process(LeaderElector.java:358) [junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$3$1.run(SolrZkClient.java:209) [junit4] 2> at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471) [junit4] 2> at java.util.concurrent.FutureTask.run(FutureTask.java:262) [junit4] 2> at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145) [junit4] 2> at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615) [junit4] 2> at java.lang.Thread.run(Thread.java:745) [junit4] 2> [junit4] 2> 1643164 T4419 oaz.ClientCnxn$EventThread.processEvent ERROR Error while calling watcher java.util.concurrent.RejectedExecutionException: Task java.util.concurrent.FutureTask@78c2a1bb rejected from java.util.concurrent.ThreadPoolExecutor@320839ed[Shutting down, pool size = 2, active threads = 2, queued tasks = 0, completed tasks = 8] [junit4] 2> at java.util.concurrent.ThreadPoolExecutor$AbortPolicy.rejectedExecution(ThreadPoolExecutor.java:2048) [junit4] 2> at java.util.concurrent.ThreadPoolExecutor.reject(ThreadPoolExecutor.java:821) [junit4] 2> at java.util.concurrent.ThreadPoolExecutor.execute(ThreadPoolExecutor.java:1372) [junit4] 2> at java.util.concurrent.AbstractExecutorService.submit(AbstractExecutorService.java:110) [junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$3.process(SolrZkClient.java:206) [junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:522) [junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:498) [junit4] 2> [junit4] 2> 1644664 T4421 oasc.LeaderElector$ElectionWatcher.process WARN org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /collections/collection1/leader_elect/shard3/election [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.getChildren(ZooKeeper.java:1472) [junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:290) [junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:287) [junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:74) [junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.getChildren(SolrZkClient.java:287) [junit4] 2> at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:94) [junit4] 2> at org.apache.solr.cloud.LeaderElector.access$200(LeaderElector.java:55) [junit4] 2> at org.apache.solr.cloud.LeaderElector$ElectionWatcher.process(LeaderElector.java:358) [junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$3$1.run(SolrZkClient.java:209) [junit4] 2> at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471) [junit4] 2> at java.util.concurrent.FutureTask.run(FutureTask.java:262) [junit4] 2> at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145) [junit4] 2> at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615) [junit4] 2> at java.lang.Thread.run(Thread.java:745) [junit4] 2> [junit4] 2> 1644667 T4352 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:40082 40082 [junit4] 2> 1645376 T4402 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:40082 40082 [junit4] 2> 1645377 T4352 oas.SolrTestCaseJ4.tearDown ###Ending testShardAssignment [junit4] 2> 1645378 T4352 oasc.Overseer.close Overseer (id=92765867425857539-127.0.0.1:40082_solr-n_0000000000) closing [junit4] 2> 1645378 T4415 oasc.Overseer$ClusterStateUpdater.run Overseer Loop exiting : 127.0.0.1:40082_solr [junit4] 2> 1645381 T4425 oasc.Overseer$ClusterStateUpdater.checkIfIamStillLeader ERROR could not read the data 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$8.execute(SolrZkClient.java:307) [junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$8.execute(SolrZkClient.java:304) [junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:74) [junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.getData(SolrZkClient.java:304) [junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.checkIfIamStillLeader(Overseer.java:320) [junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.access$300(Overseer.java:89) [junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater$1.run(Overseer.java:292) [junit4] 2> [junit4] 2> 1645385 T4352 oas.SolrTestCaseJ4.setUp ###Starting testBadQueueItem [junit4] 2> 1645386 T4352 oasc.ZkTestServer.run STARTING ZK TEST SERVER [junit4] 1> client port:0.0.0.0/0.0.0.0:0 [junit4] 2> 1645387 T4426 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server [junit4] 2> 1645487 T4352 oasc.ZkTestServer.run start zk server on port:51839 [junit4] 2> 1645488 T4352 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper [junit4] 2> 1645490 T4432 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1ff114d5 name:ZooKeeperConnection Watcher:127.0.0.1:51839 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4] 2> 1645490 T4352 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper [junit4] 2> 1645492 T4352 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper [junit4] 2> 1645493 T4434 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@3710c3f5 name:ZooKeeperConnection Watcher:127.0.0.1:51839 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4] 2> 1645493 T4352 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper [junit4] 2> 1645493 T4352 oascc.SolrZkClient.makePath makePath: /solr [junit4] 2> 1645497 T4352 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper [junit4] 2> 1645498 T4436 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@75b2f026 name:ZooKeeperConnection Watcher:127.0.0.1:51839/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4] 2> 1645498 T4352 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper [junit4] 2> 1645498 T4352 oascc.SolrZkClient.makePath makePath: /live_nodes [junit4] 2> 1645500 T4352 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper [junit4] 2> 1645501 T4438 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@2ff1aa75 name:ZooKeeperConnection Watcher:127.0.0.1:51839/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4] 2> 1645501 T4352 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper [junit4] 2> 1645501 T4352 oasu.UpdateShardHandler.<init> Creating UpdateShardHandler HTTP client with params: retry=false [junit4] 2> 1645502 T4352 oascc.SolrZkClient.makePath makePath: /overseer_elect [junit4] 2> 1645504 T4352 oascc.SolrZkClient.makePath makePath: /overseer_elect/election [junit4] 2> 1645505 T4352 oasc.Overseer.close Overseer (id=null) closing [junit4] 2> 1645507 T4352 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:51839_solr [junit4] 2> 1645507 T4352 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader [junit4] 2> 1645508 T4352 oasc.Overseer.start Overseer (id=92765867780931587-127.0.0.1:51839_solr-n_0000000000) starting [junit4] 2> 1645510 T4352 oascc.SolrZkClient.makePath makePath: /overseer/queue [junit4] 2> 1645511 T4352 oascc.SolrZkClient.makePath makePath: /overseer/queue-work [junit4] 2> 1645513 T4352 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-failure [junit4] 2> 1645515 T4352 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-running [junit4] 2> 1645516 T4352 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-completed [junit4] 2> 1645518 T4352 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work [junit4] 2> 1645520 T4352 oasc.OverseerAutoReplicaFailoverThread.<init> Starting OverseerAutoReplicaFailoverThread autoReplicaFailoverWorkLoopDelay=10000 autoReplicaFailoverWaitAfterExpiration=30000 autoReplicaFailoverBadNodeExpiration=60000 [junit4] 2> 1645520 T4440 oasc.OverseerCollectionProcessor.run Process current queue of collection creations [junit4] 2> 1645521 T4352 oascc.SolrZkClient.makePath makePath: /clusterstate.json [junit4] 2> 1645521 T4439 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue [junit4] 2> 1645522 T4352 oascc.SolrZkClient.makePath makePath: /aliases.json [junit4] 2> 1645523 T4352 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... [junit4] 2> 1645525 T4352 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper [junit4] 2> 1645525 T4443 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@10dfd41c name:ZooKeeperConnection Watcher:127.0.0.1:51839/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4] 2> 1645526 T4352 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper [junit4] 2> 1645527 T4352 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... [junit4] 2> 1645529 T4352 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1 [junit4] 2> 1645531 T4446 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged [junit4] 2> 1645532 T4439 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={ [junit4] 2> "operation":"state", [junit4] 2> "state":"active", [junit4] 2> "node_name":"127.0.0.1", [junit4] 2> "core":"core1", [junit4] 2> "core_node_name":"node1", [junit4] 2> "collection":"collection1", [junit4] 2> "numShards":"3", [junit4] 2> "base_url":"http://127.0.0.1/solr/"} [junit4] 2> 1645532 T4439 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1, shard2, shard3] [junit4] 2> 1645532 T4439 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1 [junit4] 2> 1645534 T4445 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1) [junit4] 2> 1645534 T4444 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1) [junit4] 2> 1646031 T4352 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election [junit4] 2> 1646044 T4352 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1 [junit4] 2> 1646051 T4446 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged [junit4] 2> 1646057 T4439 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={ [junit4] 2> "operation":"state", [junit4] 2> "state":"active", [junit4] 2> "node_name":"127.0.0.1", [junit4] 2> "core":"core2", [junit4] 2> "core_node_name":"node2", [junit4] 2> "collection":"collection1", [junit4] 2> "numShards":"3", [junit4] 2> "base_url":"http://127.0.0.1/solr/"} [junit4] 2> 1646057 T4439 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3 [junit4] 2> 1646058 T4439 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard3 [junit4] 2> 1646061 T4446 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged [junit4] 2> 1646062 T4445 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1) [junit4] 2> 1646062 T4444 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1) [junit4] 2> 1646553 T4352 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard3/election [junit4] 2> 1646557 T4352 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard3 [junit4] 2> 1646560 T4446 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged [junit4] 2> 1646565 T4439 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={ [junit4] 2> "operation":"state", [junit4] 2> "state":"active", [junit4] 2> "node_name":"127.0.0.1", [junit4] 2> "core":"core3", [junit4] 2> "core_node_name":"node3", [junit4] 2> "collection":"collection1", [junit4] 2> "numShards":"3", [junit4] 2> "base_url":"http://127.0.0.1/solr/"} [junit4] 2> 1646565 T4439 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3 [junit4] 2> 1646565 T4439 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard2 [junit4] 2> 1646568 T4446 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged [junit4] 2> 1646569 T4445 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1) [junit4] 2> 1646569 T4444 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1) [junit4] 2> 1647062 T4352 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard2/election [junit4] 2> 1647066 T4352 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard2 [junit4] 2> 1647069 T4446 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged [junit4] 2> 1647172 T4444 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1) [junit4] 2> 1647172 T4445 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1) [junit4] 2> 1647222 T4446 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged [junit4] 2> 1647223 T4439 oasc.Overseer$ClusterStateUpdater.checkKeyExistence ERROR Skipping invalid Overseer message because it has no collection specified: { [junit4] 2> "operation":"state", [junit4] 2> "state":"active", [junit4] 2> "node_name":"127.0.0.1", [junit4] 2> "core":"core0", [junit4] 2> "core_node_name":"node0", [junit4] 2> "collection":"", [junit4] 2> "numShards":"1", [junit4] 2> "base_url":"http://127.0.0.1/solr/"} [junit4] 2> 1647226 T4439 oasc.Overseer$ClusterStateUpdater.checkKeyExistence ERROR Skipping invalid Overseer message because it has no collection specified: { [junit4] 2> "operation":"deletecore", [junit4] 2> "node_name":"127.0.0.1", [junit4] 2> "core":"core0", [junit4] 2> "core_node_name":"node0", [junit4] 2> "collection":""} [junit4] 2> 1647229 T4446 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged [junit4] 2> 1647229 T4439 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={ [junit4] 2> "operation":"state", [junit4] 2> "state":"active", [junit4] 2> "node_name":"127.0.0.1", [junit4] 2> "core":"core1", [junit4] 2> "core_node_name":"node1", [junit4] 2> "collection":"collection2", [junit4] 2> "numShards":"3", [junit4] 2> "base_url":"http://127.0.0.1/solr/"} [junit4] 2> 1647229 T4439 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection2 with shards [shard1, shard2, shard3] [junit4] 2> 1647230 T4439 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1 [junit4] 2> 1647333 T4444 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1) [junit4] 2> 1647333 T4445 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1) [junit4] 2> 1647724 T4352 oascc.SolrZkClient.makePath makePath: /collections/collection2/leader_elect/shard1/election [junit4] 2> 1647729 T4352 oascc.SolrZkClient.makePath makePath: /collections/collection2/leaders/shard1 [junit4] 2> 1647732 T4446 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged [junit4] 2> 1647734 T4439 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={ [junit4] 2> "operation":"state", [junit4] 2> "state":"active", [junit4] 2> "node_name":"127.0.0.1", [junit4] 2> "core":"core2", [junit4] 2> "core_node_name":"node2", [junit4] 2> "collection":"collection2", [junit4] 2> "numShards":"3", [junit4] 2> "base_url":"http://127.0.0.1/solr/"} [junit4] 2> 1647734 T4439 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3 [junit4] 2> 1647735 T4439 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard3 [junit4] 2> 1647736 T4446 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged [junit4] 2> 1647736 T4445 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1) [junit4] 2> 1647736 T4444 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1) [junit4] 2> 1648233 T4352 oascc.SolrZkClient.makePath makePath: /collections/collection2/leader_elect/shard3/election [junit4] 2> 1648237 T4352 oascc.SolrZkClient.makePath makePath: /collections/collection2/leaders/shard3 [junit4] 2> 1648239 T4446 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged [junit4] 2> 1648241 T4439 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={ [junit4] 2> "operation":"state", [junit4] 2> "state":"active", [junit4] 2> "node_name":"127.0.0.1", [junit4] 2> "core":"core3", [junit4] 2> "core_node_name":"node3", [junit4] 2> "collection":"collection2", [junit4] 2> "numShards":"3", [junit4] 2> "base_url":"http://127.0.0.1/solr/"} [junit4] 2> 1648241 T4439 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3 [junit4] 2> 1648241 T4439 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard2 [junit4] 2> 1648243 T4446 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged [junit4] 2> 1648243 T4444 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1) [junit4] 2> 1648243 T4445 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1) [junit4] 2> 1648740 T4352 oascc.SolrZkClient.makePath makePath: /collections/collection2/leader_elect/shard2/election [junit4] 2> 1648744 T4352 oascc.SolrZkClient.makePath makePath: /collections/collection2/leaders/shard2 [junit4] 2> 1648746 T4446 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged [junit4] 2> 1648849 T4445 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1) [junit4] 2> 1648849 T4444 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1) [junit4] 2> 1650399 T4445 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK [junit4] 2> 1650401 T4352 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:51839 51839 [junit4] 2> 1651055 T4426 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:51839 51839 [junit4] 2> 1651056 T4352 oas.SolrTestCaseJ4.tearDown ###Ending testBadQueueItem [junit4] 2> 1651056 T4352 oasc.Overseer.close Overseer (id=92765867780931587-127.0.0.1:51839_solr-n_0000000000) closing [junit4] 2> 1651057 T4439 oasc.Overseer$ClusterStateUpdater.run Overseer Loop exiting : 127.0.0.1:51839_solr [junit4] 2> 1651059 T4447 oasc.Overseer$ClusterStateUpdater.checkIfIamStillLeader ERROR could not read the data 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$8.execute(SolrZkClient.java:307) [junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$8.execute(SolrZkClient.java:304) [junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:74) [junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.getData(SolrZkClient.java:304) [junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.checkIfIamStillLeader(Overseer.java:320) [junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.access$300(Overseer.java:89) [junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater$1.run(Overseer.java:292) [junit4] 2> [junit4] 2> 1651062 T4352 oas.SolrTestCaseJ4.setUp ###Starting testShardLeaderChange [junit4] 2> 1651063 T4352 oasc.ZkTestServer.run STARTING ZK TEST SERVER [junit4] 1> client port:0.0.0.0/0.0.0.0:0 [junit4] 2> 1651063 T4448 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server [junit4] 2> 1651163 T4352 oasc.ZkTestServer.run start zk server on port:45641 [junit4] 2> 1651164 T4352 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper [junit4] 2> 1651173 T4454 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@490e490e name:ZooKeeperConnection Watcher:127.0.0.1:45641/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4] 2> 1651174 T4352 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper [junit4] 2> 1651174 T4352 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper [junit4] 2> 1651176 T4456 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@7bde31f name:ZooKeeperConnection Watcher:127.0.0.1:45641 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4] 2> 1651176 T4352 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper [junit4] 2> 1651178 T4352 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper [junit4] 2> 1651179 T4458 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@3bc24107 name:ZooKeeperConnection Watcher:127.0.0.1:45641 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4] 2> 1651179 T4352 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper [junit4] 2> 1651179 T4352 oascc.SolrZkClient.makePath makePath: /solr [junit4] 2> 1651182 T4352 oascc.SolrZkClient.makePath makePath: /live_nodes [junit4] 2> 1651186 T4459 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper [junit4] 2> 1651186 T4352 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper [junit4] 2> 1651187 T4462 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@4e28e718 name:ZooKeeperConnection Watcher:127.0.0.1:45641/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4] 2> 1651187 T4459 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper [junit4] 2> 1651187 T4463 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@344d8833 name:ZooKeeperConnection Watcher:127.0.0.1:45641/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4] 2> 1651187 T4459 oasu.UpdateShardHandler.<init> Creating UpdateShardHandler HTTP client with params: retry=false [junit4] 2> 1651187 T4352 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper [junit4] 2> 1651188 T4459 oascc.SolrZkClient.makePath makePath: /overseer_elect [junit4] 2> 1651188 T4352 oascc.SolrZkClient.makePath makePath: /clusterstate.json [junit4] 2> 1651189 T4459 oascc.SolrZkClient.makePath makePath: /overseer_elect/election [junit4] 2> 1651190 T4352 oascc.SolrZkClient.makePath makePath: /aliases.json [junit4] 2> 1651190 T4352 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... [junit4] 2> 1651190 T4459 oasc.Overseer.close Overseer (id=null) closing [junit4] 2> 1651192 T4459 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:45641_solr [junit4] 2> 1651192 T4459 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader [junit4] 2> 1651192 T4352 oascc.SolrZkClient.makePath makePath: /live_nodes/node1 [junit4] 2> 1651193 T4459 oasc.Overseer.start Overseer (id=92765868152913923-127.0.0.1:45641_solr-n_0000000000) starting [junit4] 2> 1651194 T4352 oascc.SolrZkClient.makePath makePath: /overseer/queue [junit4] 2> 1651194 T4459 oascc.SolrZkClient.makePath makePath: /overseer/queue [junit4] 2> 1651196 T4459 oascc.SolrZkClient.makePath makePath: /overseer/queue-work [junit4] 2> 1651197 T4459 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-failure [junit4] 2> 1651198 T4459 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-running [junit4] 2> 1651199 T4459 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-completed [junit4] 2> 1651201 T4459 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work [junit4] 2> 1651203 T4459 oasc.OverseerAutoReplicaFailoverThread.<init> Starting OverseerAutoReplicaFailoverThread autoReplicaFailoverWorkLoopDelay=10000 autoReplicaFailoverWaitAfterExpiration=30000 autoReplicaFailoverBadNodeExpir [...truncated too long message...] ] 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> 1716536 T5166 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1] [junit4] 2> 1716536 T5166 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1 [junit4] 2> 1716537 T5169 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged [junit4] 2> 1716537 T5163 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1) [junit4] 2> 1716538 T5162 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1) [junit4] 2> 1717035 T4352 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election [junit4] 2> 1717040 T4352 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1 [junit4] 2> 1717042 T5169 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged [junit4] 2> 1717044 T4352 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper [junit4] 2> 1717045 T5171 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@9764032 name:ZooKeeperConnection Watcher:127.0.0.1:40514/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4] 2> 1717045 T4352 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper [junit4] 2> 1717046 T4352 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... [junit4] 2> 1717047 T4352 oascc.SolrZkClient.makePath makePath: /live_nodes/node1 [junit4] 2> 1717048 T5169 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged [junit4] 2> 1717048 T4352 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election [junit4] 2> 1717049 T5166 oasc.Overseer$ClusterStateUpdater.updateState 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> 1717049 T5166 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered [junit4] 2> 1717051 T4352 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1 [junit4] 2> 1717053 T5169 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged [junit4] 2> 1717155 T5172 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1) [junit4] 2> 1717155 T5162 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1) [junit4] 2> 1717158 T4352 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:40514 40514 [junit4] 2> 1717587 T5149 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:40514 40514 [junit4] 2> 1717588 T4352 oas.SolrTestCaseJ4.tearDown ###Ending testDoubleAssignment [junit4] 2> 1717588 T4352 oasc.Overseer.close Overseer (id=92765872434970628-127.0.0.1:40514_solr-n_0000000000) closing [junit4] 2> 1717588 T5166 oasc.Overseer$ClusterStateUpdater.run Overseer Loop exiting : 127.0.0.1:40514_solr [junit4] 2> 1717589 T5173 oasc.Overseer$ClusterStateUpdater.checkIfIamStillLeader ERROR could not read the data 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$8.execute(SolrZkClient.java:307) [junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$8.execute(SolrZkClient.java:304) [junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:74) [junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.getData(SolrZkClient.java:304) [junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.checkIfIamStillLeader(Overseer.java:320) [junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.access$300(Overseer.java:89) [junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater$1.run(Overseer.java:292) [junit4] 2> [junit4] 2> 1720589 T4352 oas.SolrTestCaseJ4.deleteCore ###deleteCore [junit4] 2> NOTE: leaving temporary files on disk at: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.10-Linux/solr/build/solr-core/test/J1/./solr.cloud.OverseerTest-5521FA015B1A02AA-001 [junit4] 2> NOTE: test params are: codec=Lucene410: {}, docValues:{}, sim=DefaultSimilarity, locale=es_PR, timezone=Europe/Tiraspol [junit4] 2> NOTE: Linux 3.13.0-39-generic amd64/Oracle Corporation 1.7.0_67 (64-bit)/cpus=8,threads=1,free=124961328,total=425721856 [junit4] 2> NOTE: All tests run in this JVM: [HdfsChaosMonkeySafeLeaderTest, CollectionsAPIDistributedZkTest, SampleTest, TimeZoneUtilsTest, HdfsLockFactoryTest, DistribDocExpirationUpdateProcessorTest, TestRecovery, TestQuerySenderNoQuery, QueryParsingTest, SolrInfoMBeanTest, StressHdfsTest, SearchHandlerTest, FieldAnalysisRequestHandlerTest, DistributedDebugComponentTest, AtomicUpdatesTest, LukeRequestHandlerTest, OverseerRolesTest, CachingDirectoryFactoryTest, PrimUtilsTest, ScriptEngineTest, AssignTest, TestConfigSets, URLClassifyProcessorTest, OverseerStatusTest, TestDistributedMissingSort, CircularListTest, DistributedQueryComponentCustomSortTest, RollingRestartTest, DateFieldTest, SolrRequestParserTest, DOMUtilTest, TestSolrQueryParserResource, TestExpandComponent, TestFunctionQuery, BasicZkTest, AlternateDirectoryTest, AnalysisAfterCoreReloadTest, TestReplicationHandlerBackup, AutoCommitTest, TestSweetSpotSimilarityFactory, TestJoin, TestClassNameShortening, TestBinaryField, TestRecoveryHdfs, BlockCacheTest, SystemInfoHandlerTest, DefaultValueUpdateProcessorTest, FullSolrCloudDistribCmdsTest, DebugComponentTest, SchemaVersionSpecificBehaviorTest, TestExtendedDismaxParser, SolrCoreTest, TestFileDictionaryLookup, StatsComponentTest, TestLRUCache, TestManagedResourceStorage, SynonymTokenizerTest, TestHighFrequencyDictionaryFactory, TestFastLRUCache, TestReRankQParserPlugin, LegacyHTMLStripCharFilterTest, UpdateRequestProcessorFactoryTest, HdfsUnloadDistributedZkTest, SpatialFilterTest, TestUpdate, HardAutoCommitTest, MultiTermTest, TestDistributedGrouping, HdfsWriteToMultipleCollectionsTest, ChaosMonkeySafeLeaderTest, RemoteQueryErrorTest, TestStandardQParsers, AsyncMigrateRouteKeyTest, DistributedFacetPivotLargeTest, CurrencyFieldXmlFileTest, TestIndexingPerformance, BinaryUpdateRequestHandlerTest, FileBasedSpellCheckerTest, TestCSVLoader, TestSolrQueryParser, HdfsDirectoryTest, TestShortCircuitedRequests, TestCharFilters, SuggesterFSTTest, TestOmitPositions, CacheHeaderTest, TestManagedResource, TestFieldTypeCollectionResource, TestNonNRTOpen, TestMaxScoreQueryParser, CopyFieldTest, TestDynamicFieldCollectionResource, IndexSchemaRuntimeFieldTest, DistanceFunctionTest, ResponseHeaderTest, TestElisionMultitermQuery, DistributedFacetPivotSmallTest, SSLMigrationTest, TestQueryTypes, TestPostingsSolrHighlighter, NumericFieldsTest, TestLMDirichletSimilarityFactory, BasicDistributedZk2Test, OpenCloseCoreStressTest, OverseerTest] [junit4] Completed on J1 in 100.14s, 9 tests, 1 error <<< FAILURES! [...truncated 682 lines...] BUILD FAILED /mnt/ssd/jenkins/workspace/Lucene-Solr-4.10-Linux/build.xml:474: The following error occurred while executing this line: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.10-Linux/build.xml:454: The following error occurred while executing this line: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.10-Linux/build.xml:45: The following error occurred while executing this line: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.10-Linux/extra-targets.xml:37: The following error occurred while executing this line: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.10-Linux/solr/build.xml:189: The following error occurred while executing this line: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.10-Linux/solr/common-build.xml:494: The following error occurred while executing this line: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.10-Linux/lucene/common-build.xml:1350: The following error occurred while executing this line: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.10-Linux/lucene/common-build.xml:970: There were test failures: 421 suites, 1742 tests, 1 error, 38 ignored (17 assumptions) Total time: 95 minutes 42 seconds Build step 'Invoke Ant' marked build as failure [description-setter] Description set: Java: 64bit/jdk1.7.0_67 -XX:-UseCompressedOops -XX:+UseParallelGC (asserts: true) Archiving artifacts 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