lucene-dev mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From Policeman Jenkins Server <jenk...@thetaphi.de>
Subject [JENKINS] Lucene-Solr-trunk-Windows (64bit/jdk1.7.0_51) - Build # 3853 - Still Failing!
Date Tue, 11 Mar 2014 18:05:42 GMT
Build: http://jenkins.thetaphi.de/job/Lucene-Solr-trunk-Windows/3853/
Java: 64bit/jdk1.7.0_51 -XX:+UseCompressedOops -XX:+UseG1GC -XX:-UseSuperWord

1 tests failed.
REGRESSION:  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([EEEBC047CAF8209A:EAE34FB4D85DCFBB]:0)
	at org.apache.solr.cloud.ShardLeaderElectionContextBase.runLeaderProcess(ElectionContext.java:135)
	at org.apache.solr.cloud.LeaderElector.runIamLeaderProcess(LeaderElector.java:164)
	at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:108)
	at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:156)
	at org.apache.solr.cloud.LeaderElector.joinElection(LeaderElector.java:289)
	at org.apache.solr.cloud.OverseerTest$MockZKController.publishState(OverseerTest.java:155)
	at org.apache.solr.cloud.OverseerTest.testOverseerFailure(OverseerTest.java:666)
	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:1617)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:826)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:862)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:876)
	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:70)
	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:359)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:783)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:443)
	at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:835)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:737)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:771)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:782)
	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 org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:43)
	at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
	at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
	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:359)
	at java.lang.Thread.run(Thread.java:744)
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$10.execute(SolrZkClient.java:431)
	at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
	at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:428)
	at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:385)
	at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:372)
	at org.apache.solr.cloud.ShardLeaderElectionContextBase$1.execute(ElectionContext.java:127)
	at org.apache.solr.common.util.RetryUtil.retryOnThrowable(RetryUtil.java:31)
	at org.apache.solr.cloud.ShardLeaderElectionContextBase.runLeaderProcess(ElectionContext.java:122)
	... 45 more




Build Log:
[...truncated 10527 lines...]
   [junit4] Suite: org.apache.solr.cloud.OverseerTest
   [junit4]   2> 2513119 T6326 oas.SolrTestCaseJ4.buildSSLConfig Randomized ssl (false) and clientAuth (true)
   [junit4]   2> 2513120 T6326 oas.SolrTestCaseJ4.initCore ####initCore
   [junit4]   2> Creating dataDir: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\solrtest-OverseerTest-1394559393517
   [junit4]   2> 2513124 T6326 oas.SolrTestCaseJ4.initCore ####initCore end
   [junit4]   2> 2513136 T6326 oas.SolrTestCaseJ4.setUp ###Starting testShardAssignment
   [junit4]   2> 2513139 T6326 oasc.ZkTestServer.run STARTING ZK TEST SERVER
   [junit4]   2> 2513141 T6327 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
   [junit4]   2> 2513260 T6326 oasc.ZkTestServer.run start zk server on port:65222
   [junit4]   2> 2513265 T6326 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 2513279 T6333 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@7f3a9d0 name:ZooKeeperConnection Watcher:127.0.0.1:65222 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 2513280 T6326 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 2513290 T6326 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 2513295 T6335 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@24957d6b name:ZooKeeperConnection Watcher:127.0.0.1:65222 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 2513297 T6326 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 2513297 T6326 oascc.SolrZkClient.makePath makePath: /solr
   [junit4]   2> 2513319 T6326 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 2513341 T6337 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@d7824b name:ZooKeeperConnection Watcher:127.0.0.1:65222/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 2513342 T6326 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 2513342 T6326 oascc.SolrZkClient.makePath makePath: /live_nodes
   [junit4]   2> 2513350 T6326 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 2513356 T6339 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@74b0cbd6 name:ZooKeeperConnection Watcher:127.0.0.1:65222/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 2513357 T6326 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 2513361 T6326 oascc.SolrZkClient.makePath makePath: /overseer_elect
   [junit4]   2> 2513368 T6326 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
   [junit4]   2> 2513386 T6326 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:65222_solr
   [junit4]   2> 2513387 T6326 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
   [junit4]   2> 2513394 T6326 oasc.Overseer.start Overseer (id=91393844415823875-127.0.0.1:65222_solr-n_0000000000) starting
   [junit4]   2> 2513403 T6326 oascc.SolrZkClient.makePath makePath: /overseer/queue
   [junit4]   2> 2513415 T6326 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
   [junit4]   2> 2513440 T6326 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
   [junit4]   2> 2513458 T6341 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
   [junit4]   2> 2513460 T6341 oasc.OverseerCollectionProcessor.prioritizeOverseerNodes prioritizing overseer nodes
   [junit4]   2> 2513462 T6326 oascc.SolrZkClient.makePath makePath: /clusterstate.json
   [junit4]   2> 2513463 T6340 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
   [junit4]   2> 2513470 T6326 oascc.SolrZkClient.makePath makePath: /aliases.json
   [junit4]   2> 2513477 T6326 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 2513494 T6326 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 2513505 T6343 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@37dcbba6 name:ZooKeeperConnection Watcher:127.0.0.1:65222/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 2513507 T6326 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 2513511 T6326 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 2513518 T6326 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1
   [junit4]   2> 2513526 T6337 oascc.ZkStateReader$3.process Updating live nodes... (1)
   [junit4]   2> 2513527 T6343 oascc.ZkStateReader$3.process Updating live nodes... (1)
   [junit4]   2> 2513534 T6339 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2513538 T6340 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 2513539 T6340 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> 2513539 T6340 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1, shard2, shard3]
   [junit4]   2> 2513539 T6340 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard2
   [junit4]   2> 2513548 T6339 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2513551 T6337 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> 2513552 T6343 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> 2514128 T6326 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard2/election
   [junit4]   2> 2514163 T6326 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard2
   [junit4]   2> 2514185 T6339 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2514193 T6339 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2514193 T6340 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 2514207 T6340 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> 2514207 T6340 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
   [junit4]   2> 2514207 T6340 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
   [junit4]   2> 2514217 T6339 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2514341 T6343 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> 2514342 T6337 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> 2514785 T6326 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
   [junit4]   2> 2514810 T6326 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 2514828 T6339 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2514829 T6339 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2514829 T6339 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2514841 T6339 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2514842 T6340 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 2514853 T6340 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> 2514853 T6340 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
   [junit4]   2> 2514853 T6340 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard3
   [junit4]   2> 2514864 T6339 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2514987 T6337 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> 2514989 T6343 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> 2515433 T6326 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard3/election
   [junit4]   2> 2515454 T6326 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard3
   [junit4]   2> 2515468 T6339 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2515468 T6339 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2515468 T6339 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2515493 T6339 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2515497 T6340 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 2515510 T6340 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> 2515510 T6340 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
   [junit4]   2> 2515510 T6340 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard2
   [junit4]   2> 2515521 T6339 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2515645 T6343 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> 2515646 T6337 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> 2516087 T6326 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard2/election
   [junit4]   2> 2516110 T6339 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2516110 T6339 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2516110 T6339 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2516114 T6340 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 2516117 T6340 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> 2516117 T6340 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
   [junit4]   2> 2516117 T6340 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
   [junit4]   2> 2516127 T6339 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2516251 T6337 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> 2516252 T6343 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> 2516702 T6326 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
   [junit4]   2> 2516726 T6339 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2516726 T6339 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2516727 T6339 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2516731 T6340 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 2516732 T6340 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> 2516732 T6340 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
   [junit4]   2> 2516732 T6340 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard3
   [junit4]   2> 2516741 T6339 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2516865 T6343 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> 2516865 T6337 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> 2517319 T6326 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard3/election
   [junit4]   2> 2517378 T6343 oascc.ZkStateReader$3.process Updating live nodes... (0)
   [junit4]   2> 2517393 T6326 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:65222 65222
   [junit4]   2> 2519156 T6343 oasc.LeaderElector$1.process WARN  org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /collections/collection1/leader_elect/shard2/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:1468)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:259)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:256)
   [junit4]   2> 	at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient.getChildren(SolrZkClient.java:256)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:92)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector.access$000(LeaderElector.java:55)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector$1.process(LeaderElector.java:137)
   [junit4]   2> 	at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:519)
   [junit4]   2> 	at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:495)
   [junit4]   2> 
   [junit4]   2> 2520062 T6343 oasc.LeaderElector$1.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:1468)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:259)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:256)
   [junit4]   2> 	at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient.getChildren(SolrZkClient.java:256)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:92)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector.access$000(LeaderElector.java:55)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector$1.process(LeaderElector.java:137)
   [junit4]   2> 	at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:519)
   [junit4]   2> 	at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:495)
   [junit4]   2> 
   [junit4]   2> 2520066 T6343 oasc.LeaderElector$1.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:1468)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:259)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:256)
   [junit4]   2> 	at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient.getChildren(SolrZkClient.java:256)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:92)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector.access$000(LeaderElector.java:55)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector$1.process(LeaderElector.java:137)
   [junit4]   2> 	at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:519)
   [junit4]   2> 	at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:495)
   [junit4]   2> 
   [junit4]   2> 2520066 T6326 oas.SolrTestCaseJ4.tearDown ###Ending testShardAssignment
   [junit4]   1> client port:0.0.0.0/0.0.0.0:0
   [junit4]   2> 2520089 T6326 oas.SolrTestCaseJ4.setUp ###Starting testStateChange
   [junit4]   2> 2520091 T6326 oasc.ZkTestServer.run STARTING ZK TEST SERVER
   [junit4]   2> 2520092 T6344 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
   [junit4]   2> 2520211 T6326 oasc.ZkTestServer.run start zk server on port:65240
   [junit4]   2> 2520214 T6326 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 2520228 T6350 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@6b8781b4 name:ZooKeeperConnection Watcher:127.0.0.1:65240/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 2520228 T6326 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 2520239 T6326 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 2520241 T6352 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1d9a96f5 name:ZooKeeperConnection Watcher:127.0.0.1:65240 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 2520242 T6326 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 2520339 T6326 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 2520345 T6354 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@65fedd4b name:ZooKeeperConnection Watcher:127.0.0.1:65240 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 2520345 T6326 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 2520345 T6326 oascc.SolrZkClient.makePath makePath: /solr
   [junit4]   2> 2520355 T6326 oascc.SolrZkClient.makePath makePath: /live_nodes
   [junit4]   2> 2520366 T6326 oascc.SolrZkClient.makePath makePath: /clusterstate.json
   [junit4]   2> 2520372 T6326 oascc.SolrZkClient.makePath makePath: /aliases.json
   [junit4]   2> 2520376 T6326 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 2520387 T6326 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 2520393 T6356 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1e7c565 name:ZooKeeperConnection Watcher:127.0.0.1:65240/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 2520393 T6326 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 2520395 T6326 oascc.SolrZkClient.makePath makePath: /overseer_elect
   [junit4]   2> 2520402 T6326 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
   [junit4]   2> 2520417 T6326 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:65240_solr
   [junit4]   2> 2520418 T6326 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
   [junit4]   2> 2520426 T6326 oasc.Overseer.start Overseer (id=91393844871561219-127.0.0.1:65240_solr-n_0000000000) starting
   [junit4]   2> 2520433 T6326 oascc.SolrZkClient.makePath makePath: /overseer/queue
   [junit4]   2> 2520445 T6326 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
   [junit4]   2> 2520456 T6326 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
   [junit4]   2> 2520464 T6358 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
   [junit4]   2> 2520468 T6358 oasc.OverseerCollectionProcessor.prioritizeOverseerNodes prioritizing overseer nodes
   [junit4]   2> 2520469 T6357 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
   [junit4]   2> 2520472 T6326 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 2520478 T6357 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 2520479 T6357 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> 2520479 T6357 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
   [junit4]   2> 2520489 T6356 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2520491 T6350 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> 2520537 T6326 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 2520545 T6356 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2520550 T6357 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 2520551 T6357 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> 2520552 T6357 oasc.Overseer$ClusterStateUpdater.updateState node=core_node1 is already registered
   [junit4]   2> 2520552 T6357 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
   [junit4]   2> 2520560 T6356 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2520692 T6350 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> 2520740 T6345 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x144b237ba3a0000, likely client has closed socket
   [junit4]   2> 	at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:220)
   [junit4]   2> 	at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208)
   [junit4]   2> 	at java.lang.Thread.run(Thread.java:744)
   [junit4]   2> 
   [junit4]   2> 2520749 T6326 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:65240 65240
   [junit4]   2> 2523486 T6326 oas.SolrTestCaseJ4.tearDown ###Ending testStateChange
   [junit4]   1> client port:0.0.0.0/0.0.0.0:0
   [junit4]   2> 2523508 T6326 oas.SolrTestCaseJ4.setUp ###Starting testOverseerFailure
   [junit4]   2> 2523509 T6326 oasc.ZkTestServer.run STARTING ZK TEST SERVER
   [junit4]   2> 2523510 T6359 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
   [junit4]   2> 2523641 T6326 oasc.ZkTestServer.run start zk server on port:65255
   [junit4]   2> 2523645 T6326 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 2523658 T6365 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@22df6094 name:ZooKeeperConnection Watcher:127.0.0.1:65255 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 2523659 T6326 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 2523705 T6360 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x144b237c7950000, likely client has closed socket
   [junit4]   2> 	at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:220)
   [junit4]   2> 	at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208)
   [junit4]   2> 	at java.lang.Thread.run(Thread.java:744)
   [junit4]   2> 
   [junit4]   2> 2523709 T6326 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 2523717 T6367 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@4eb06a69 name:ZooKeeperConnection Watcher:127.0.0.1:65255 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 2523717 T6326 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 2523718 T6326 oascc.SolrZkClient.makePath makePath: /solr
   [junit4]   2> 2523725 T6360 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x144b237c7950001, likely client has closed socket
   [junit4]   2> 	at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:220)
   [junit4]   2> 	at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208)
   [junit4]   2> 	at java.lang.Thread.run(Thread.java:744)
   [junit4]   2> 
   [junit4]   2> 2523729 T6326 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 2523736 T6369 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@5420f335 name:ZooKeeperConnection Watcher:127.0.0.1:65255/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 2523737 T6326 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 2523737 T6326 oascc.SolrZkClient.makePath makePath: /live_nodes
   [junit4]   2> 2523746 T6326 oascc.SolrZkClient.makePath makePath: /clusterstate.json
   [junit4]   2> 2523755 T6326 oascc.SolrZkClient.makePath makePath: /aliases.json
   [junit4]   2> 2523761 T6326 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 2523778 T6326 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 2523784 T6371 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@3664f71b name:ZooKeeperConnection Watcher:127.0.0.1:65255/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 2523785 T6326 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 2523790 T6326 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 2523799 T6326 oascc.SolrZkClient.makePath makePath: /live_nodes/node1
   [junit4]   2> 2523807 T6371 oascc.ZkStateReader$3.process Updating live nodes... (1)
   [junit4]   2> 2523808 T6369 oascc.ZkStateReader$3.process Updating live nodes... (1)
   [junit4]   2> 2523812 T6326 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 2523817 T6373 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@11cba930 name:ZooKeeperConnection Watcher:127.0.0.1:65255/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 2523818 T6326 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 2523822 T6326 oascc.SolrZkClient.makePath makePath: /overseer_elect
   [junit4]   2> 2523830 T6326 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
   [junit4]   2> 2523845 T6326 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:65255_solr
   [junit4]   2> 2523845 T6326 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
   [junit4]   2> 2523854 T6326 oasc.Overseer.start Overseer (id=91393845095628804-127.0.0.1:65255_solr-n_0000000000) starting
   [junit4]   2> 2523862 T6326 oascc.SolrZkClient.makePath makePath: /overseer/queue
   [junit4]   2> 2523872 T6326 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
   [junit4]   2> 2523886 T6326 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
   [junit4]   2> 2523893 T6375 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
   [junit4]   2> 2523897 T6375 oasc.OverseerCollectionProcessor.prioritizeOverseerNodes prioritizing overseer nodes
   [junit4]   2> 2523897 T6374 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
   [junit4]   2> 2525203 T6373 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2525208 T6374 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 2525211 T6374 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> 2525211 T6374 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1]
   [junit4]   2> 2525211 T6374 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
   [junit4]   2> 2525219 T6373 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2525222 T6371 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> 2525223 T6369 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> 2525854 T6326 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
   [junit4]   2> 2525884 T6326 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 2525907 T6373 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2525908 T6326 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 2525912 T6374 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 2525921 T6373 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2525921 T6326 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
   [junit4]   2> 2525926 T6374 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> 2525927 T6374 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
   [junit4]   2> 2525935 T6373 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2526073 T6369 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> 2526073 T6371 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> 2526082 T6360 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x144b237c7950004, likely client has closed socket
   [junit4]   2> 	at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:220)
   [junit4]   2> 	at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208)
   [junit4]   2> 	at java.lang.Thread.run(Thread.java:744)
   [junit4]   2> 
   [junit4]   2> 2527392 T6326 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
   [junit4]   2> 2527410 T6326 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 2527416 T6377 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1e128d32 name:ZooKeeperConnection Watcher:127.0.0.1:65255/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 2527417 T6326 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 2527430 T6326 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:65255_solr
   [junit4]   2> 2527431 T6326 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
   [junit4]   2> 2527436 T6326 oasc.Overseer.start Overseer (id=91393845095628805-127.0.0.1:65255_solr-n_0000000001) starting
   [junit4]   2> 2527452 T6379 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
   [junit4]   2> 2527453 T6379 oasc.OverseerCollectionProcessor.prioritizeOverseerNodes prioritizing overseer nodes
   [junit4]   2> 2527457 T6378 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 2527461 T6378 oasc.Overseer$ClusterStateUpdater.run Replaying operations from work queue.
   [junit4]   2> 2527464 T6371 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> 2527464 T6369 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> 2527475 T6378 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> 2527475 T6378 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
   [junit4]   2> 2527478 T6369 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> 2527480 T6371 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> 2527486 T6378 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
   [junit4]   2> 2527492 T6378 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 2527494 T6378 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> 2527494 T6378 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
   [junit4]   2> 2527500 T6377 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2527503 T6371 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> 2527504 T6369 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> 2527539 T6377 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2527541 T6326 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
   [junit4]   2> 2527545 T6378 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 2527560 T6371 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 2527562 T6326 oasc.LeaderElector.checkIfIamLeader WARN Failed setting watch org.apache.zookeeper.KeeperException$NoNodeException: KeeperErrorCode = NoNode for /collections/collection1/leader_elect/shard1/election/91393845095628803-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:1151)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:276)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:273)
   [junit4]   2> 	at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient.getData(SolrZkClient.java:273)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:125)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector.joinElection(LeaderElector.java:289)
   [junit4]   2> 	at org.apache.solr.cloud.OverseerTest$MockZKController.publishState(OverseerTest.java:155)
   [junit4]   2> 	at org.apache.solr.cloud.OverseerTest.testOverseerFailure(OverseerTest.java:666)
   [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:1617)
   [junit4]   2> 	at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:826)
   [junit4]   2> 	at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:862)
   [junit4]   2> 	at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:876)
   [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:70)
   [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:359)
   [junit4]   2> 	at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:783)
   [junit4]   2> 	at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:443)
   [junit4]   2> 	at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:835)
   [junit4]   2> 	at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:737)
   [junit4]   2> 	at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:771)
   [junit4]   2> 	at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:782)
   [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 org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:43)
   [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:70)
   [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:359)
   [junit4]   2> 	at java.lang.Thread.run(Thread.java:744)
   [junit4]   2> 
   [junit4]   2> 2527574 T6326 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 2527574 T6378 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:176)
   [junit4]   2> 		at org.apache.solr.common.cloud.SolrZkClient$2.execute(SolrZkClient.java:173)
   [junit4]   2> 		at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
   [junit4]   2> 		at org.apache.solr.common.cloud.SolrZkClient.delete(SolrZkClient.java:173)
   [junit4]   2> 		at org.apache.solr.common.cloud.SolrZkClient.clean(SolrZkClient.java:635)
   [junit4]   2> 		at org.apache.solr.common.cloud.SolrZkClient.clean(SolrZkClient.java:630)
   [junit4]   2> 		at org.apache.solr.common.cloud.SolrZkClient.clean(SolrZkClient.java:630)
   [junit4]   2> 		at org.apache.solr.common.cloud.SolrZkClient.clean(SolrZkClient.java:630)
   [junit4]   2> 		at org.apache.solr.cloud.Overseer$ClusterStateUpdater.removeCore(Overseer.java:976)
   [junit4]   2> 		at org.apache.solr.cloud.Overseer$ClusterStateUpdater.processMessage(Overseer.java:253)
   [junit4]   2> 		at org.apache.solr.cloud.Overseer$ClusterStateUpdater.run(Overseer.java:202)
   [junit4]   2> 		at java.lang.Thread.run(Thread.java:744)
   [junit4]   2> 	
   [junit4]   2> 2527586 T6377 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2527593 T6371 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 2527593 T6378 oasc.Overseer$ClusterStateUpdater.setShardLeader ERROR Could not mark shard leader for non existing collection:collection1
   [junit4]   2> 2527608 T6377 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2527614 T6377 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2527617 T6378 oasc.Overseer$ClusterStateUpdater.setShardLeader ERROR Could not mark shard leader for non existing collection:collection1
   [junit4]   2> 2527627 T6377 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2527766 T6369 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> 2527766 T6371 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> 2528892 T6326 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 2530204 T6326 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 2531516 T6326 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 2532830 T6326 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 2534140 T6326 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 2535456 T6326 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 2536861 T6326 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 2538304 T6326 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 2539746 T6326 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 2541186 T6326 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 2542628 T6326 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 2544070 T6326 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 2545512 T6326 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 2546953 T6326 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 2548394 T6326 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 2548405 T6369 oascc.ZkStateReader$3.process Updating live nodes... (0)
   [junit4]   2> 2548406 T6371 oascc.ZkStateReader$3.process Updating live nodes... (0)
   [junit4]   2> 2548412 T6360 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x144b237c7950003, likely client has closed socket
   [junit4]   2> 	at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:220)
   [junit4]   2> 	at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208)
   [junit4]   2> 	at java.lang.Thread.run(Thread.java:744)
   [junit4]   2> 
   [junit4]   2> 2548416 T6360 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x144b237c7950005, likely client has closed socket
   [junit4]   2> 	at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:220)
   [junit4]   2> 	at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208)
   [junit4]   2> 	at java.lang.Thread.run(Thread.java:744)
   [junit4]   2> 
   [junit4]   2> 2548426 T6326 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:65255 65255
   [junit4]   2> 2551510 T6326 oas.SolrTestCaseJ4.tearDown ###Ending testOverseerFailure
   [junit4]   1> client port:0.0.0.0/0.0.0.0:0
   [junit4]   2> NOTE: reproduce with: ant test  -Dtestcase=OverseerTest -Dtests.method=testOverseerFailure -Dtests.seed=EEEBC047CAF8209A -Dtests.slow=true -Dtests.locale=ja_JP_JP_#u-ca-japanese -Dtests.timezone=Etc/GMT-9 -Dtests.file.encoding=Cp1252
   [junit4] ERROR   28.1s | 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([EEEBC047CAF8209A:EAE34FB4D85DCFBB]:0)
   [junit4]    > 	at org.apache.solr.cloud.ShardLeaderElectionContextBase.runLeaderProcess(ElectionContext.java:135)
   [junit4]    > 	at org.apache.solr.cloud.LeaderElector.runIamLeaderProcess(LeaderElector.java:164)
   [junit4]    > 	at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:108)
   [junit4]    > 	at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:156)
   [junit4]    > 	at org.apache.solr.cloud.LeaderElector.joinElection(LeaderElector.java:289)
   [junit4]    > 	at org.apache.solr.cloud.OverseerTest$MockZKController.publishState(OverseerTest.java:155)
   [junit4]    > 	at org.apache.solr.cloud.OverseerTest.testOverseerFailure(OverseerTest.java:666)
   [junit4]    > 	at java.lang.Thread.run(Thread.java:744)
   [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$10.execute(SolrZkClient.java:431)
   [junit4]    > 	at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
   [junit4]    > 	at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:428)
   [junit4]    > 	at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:385)
   [junit4]    > 	at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:372)
   [junit4]    > 	at org.apache.solr.cloud.ShardLeaderElectionContextBase$1.execute(ElectionContext.java:127)
   [junit4]    > 	at org.apache.solr.common.util.RetryUtil.retryOnThrowable(RetryUtil.java:31)
   [junit4]    > 	at org.apache.solr.cloud.ShardLeaderElectionContextBase.runLeaderProcess(ElectionContext.java:122)
   [junit4]    > 	... 45 more
   [junit4]   2> 2551555 T6326 oas.SolrTestCaseJ4.setUp ###Starting testReplay
   [junit4]   2> 2551555 T6326 oasc.ZkTestServer.run STARTING ZK TEST SERVER
   [junit4]   2> 2551558 T6380 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
   [junit4]   2> 2551687 T6326 oasc.ZkTestServer.run start zk server on port:65276
   [junit4]   2> 2551690 T6326 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 2551699 T6386 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@2cbcf2e8 name:ZooKeeperConnection Watcher:127.0.0.1:65276/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 2551700 T6326 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 2551703 T6326 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 2551709 T6388 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@711ad34 name:ZooKeeperConnection Watcher:127.0.0.1:65276 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 2551709 T6326 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 2551758 T6326 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 2551762 T6390 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@3ef4f460 name:ZooKeeperConnection Watcher:127.0.0.1:65276 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 2551763 T6326 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 2551763 T6326 oascc.SolrZkClient.makePath makePath: /solr
   [junit4]   2> 2551769 T6326 oascc.SolrZkClient.makePath makePath: /live_nodes
   [junit4]   2> 2551769 T6381 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x144b23835230002, likely client has closed socket
   [junit4]   2> 	at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:220)
   [junit4]   2> 	at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208)
   [junit4]   2> 	at java.lang.Thread.run(Thread.java:744)
   [junit4]   2> 
   [junit4]   2> 2551779 T6326 oascc.SolrZkClient.makePath makePath: /clusterstate.json
   [junit4]   2> 2551786 T6326 oascc.SolrZkClient.makePath makePath: /aliases.json
   [junit4]   2> 2551791 T6326 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 2551805 T6326 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
   [junit4]   2> 2551816 T6326 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 2551821 T6392 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@8a98e0a name:ZooKeeperConnection Watcher:127.0.0.1:65276/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 2551821 T6326 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 2551823 T6326 oascc.SolrZkClient.makePath makePath: /overseer_elect
   [junit4]   2> 2551829 T6326 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
   [junit4]   2> 2551836 T6326 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:65276_solr
   [junit4]   2> 2551837 T6326 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
   [junit4]   2> 2551842 T6326 oasc.Overseer.start Overseer (id=91393846933651459-127.0.0.1:65276_solr-n_0000000000) starting
   [junit4]   2> 2551846 T6326 oascc.SolrZkClient.makePath makePath: /overseer/queue
   [junit4]   2> 2551858 T6326 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
   [junit4]   2> 2551864 T6394 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
   [junit4]   2> 2551866 T6394 oasc.OverseerCollectionProcessor.prioritizeOverseerNodes prioritizing overseer nodes
   [junit4]   2> 2551870 T6393 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 2551871 T6393 oasc.Overseer$ClusterStateUpdater.run Replaying operations from work queue.
   [junit4]   2> 2551873 T6393 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> 	  "shard":"s1",
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "core":"core1",
   [junit4]   2> 	  "roles":"",
   [junit4]   2> 	  "state":"recovering"}
   [junit4]   2> 2551875 T6386 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> 2551881 T6393 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> 	  "shard":"s1",
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "core":"core2",
   [junit4]   2> 	  "roles":"",
   [junit4]   2> 	  "state":"recovering"}
   [junit4]   2> 2551884 T6386 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> 2551890 T6393 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
   [junit4]   2> 2551895 T6393 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 2551898 T6393 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> 	  "shard":"s1",
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "core":"core3",
   [junit4]   2> 	  "roles":"",
   [junit4]   2> 	  "state":"recovering"}
   [junit4]   2> 2551907 T6392 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2551908 T6386 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> 2552002 T6381 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x144b23835230003, likely client has closed socket
   [junit4]   2> 	at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:220)
   [junit4]   2> 	at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208)
   [junit4]   2> 	at java.lang.Thread.run(Thread.java:744)
   [junit4]   2> 
   [junit4]   2> 2552009 T6381 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x144b23835230000, likely client has closed socket
   [junit4]   2> 	at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:220)
   [junit4]   2> 	at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208)
   [junit4]   2> 	at java.lang.Thread.run(Thread.java:744)
   [junit4]   2> 
   [junit4]   2> 2552011 T6326 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:65276 65276
   [junit4]   2> 2554921 T6326 oas.SolrTestCaseJ4.tearDown ###Ending testReplay
   [junit4]   1> client port:0.0.0.0/0.0.0.0:0
   [junit4]   2> 2554935 T6326 oas.SolrTestCaseJ4.setUp ###Starting testShardLeaderChange
   [junit4]   2> 2554935 T6326 oasc.ZkTestServer.run STARTING ZK TEST SERVER
   [junit4]   2> 2554936 T6395 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
   [junit4]   2> 2555066 T6326 oasc.ZkTestServer.run start zk server on port:65291
   [junit4]   2> 2555069 T6326 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 2555076 T6401 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@75445b87 name:ZooKeeperConnection Watcher:127.0.0.1:65291/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 2555078 T6326 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 2555080 T6326 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 2555084 T6403 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@28157439 name:ZooKeeperConnection Watcher:127.0.0.1:65291 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 2555085 T6326 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 2555120 T6396 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x144b23842510001, likely client has closed socket
   [junit4]   2> 	at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:220)
   [junit4]   2> 	at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208)
   [junit4]   2> 	at java.lang.Thread.run(Thread.java:744)
   [junit4]   2> 
   [junit4]   2> 2555123 T6326 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 2555128 T6405 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@2acc1fe9 name:ZooKeeperConnection Watcher:127.0.0.1:65291 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 2555129 T6326 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 2555129 T6326 oascc.SolrZkClient.makePath makePath: /solr
   [junit4]   2> 2555139 T6326 oascc.SolrZkClient.makePath makePath: /live_nodes
   [junit4]   2> 2555156 T6326 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 2555158 T6406 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 2555164 T6409 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@3c1fff65 name:ZooKeeperConnection Watcher:127.0.0.1:65291/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 2555164 T6326 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 2555164 T6410 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@58b85eb9 name:ZooKeeperConnection Watcher:127.0.0.1:65291/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 2555167 T6406 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 2555170 T6326 oascc.SolrZkClient.makePath makePath: /clusterstate.json
   [junit4]   2> 2555170 T6406 oascc.SolrZkClient.makePath makePath: /overseer_elect
   [junit4]   2> 2555175 T6326 oascc.SolrZkClient.makePath makePath: /aliases.json
   [junit4]   2> 2555175 T6406 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
   [junit4]   2> 2555180 T6326 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 2555187 T6406 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:65291_solr
   [junit4]   2> 2555187 T6406 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
   [junit4]   2> 2555188 T6326 oascc.SolrZkClient.makePath makePath: /live_nodes/node1
   [junit4]   2> 2555192 T6406 oasc.Overseer.start Overseer (id=91393847154769924-127.0.0.1:65291_solr-n_0000000000) starting
   [junit4]   2> 2555198 T6409 oascc.ZkStateReader$3.process Updating live nodes... (1)
   [junit4]   2> 2555201 T6406 oascc.SolrZkClient.makePath makePath: /overseer/queue
   [junit4]   2> 2555201 T6326 oascc.SolrZkClient.makePath makePath: /overseer/queue
   [junit4]   2> 2555209 T6406 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
   [junit4]   2> 2555219 T6406 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
   [junit4]   2> 2555224 T6406 oasc.OverseerTest$OverseerRestarter.run Killing overseer.
   [junit4]   2> 2555225 T6412 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
   [junit4]   2> 2555227 T6396 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x144b23842510004, likely client has closed socket
   [junit4]   2> 	at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:220)
   [junit4]   2> 	at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208)
   [junit4]   2> 	at java.lang.Thread.run(Thread.java:744)
   [junit4]   2> 
   [junit4]   2> 2555227 T6411 oasc.Overseer$ClusterStateUpdater.run WARN Solr cannot talk to ZK, exiting Overseer work queue loop org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /overseer/queue-work
   [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:1468)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:259)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:256)
   [junit4]   2> 	at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient.getChildren(SolrZkClient.java:256)
   [junit4]   2> 	at org.apache.solr.cloud.DistributedQueue.orderedChildren(DistributedQueue.java:89)
   [junit4]   2> 	at org.apache.solr.cloud.DistributedQueue.element(DistributedQueue.java:131)
   [junit4]   2> 	at org.apache.solr.cloud.DistributedQueue.peek(DistributedQueue.java:325)
   [junit4]   2> 	at org.apache.solr.cloud.Overseer$ClusterStateUpdater.run(Overseer.java:111)
   [junit4]   2> 	at java.lang.Thread.run(Thread.java:744)
   [junit4]   2> 
   [junit4]   2> 2555229 T6406 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 2555235 T6414 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@28b51ab6 name:ZooKeeperConnection Watcher:127.0.0.1:65291/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 2555236 T6406 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 2555238 T6412 oasc.OverseerCollectionProcessor.amILeader According to ZK I (id=91393847154769924-127.0.0.1:65291_solr-n_0000000000) am no longer a leader.
   [junit4]   2> 2555238 T6412 oasc.OverseerCollectionProcessor.prioritizeOverseerNodes prioritizing overseer nodes
   [junit4]   2> 2555238 T6412 oasc.OverseerCollectionProcessor.run ERROR Unable to prioritize overseer  org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /roles.json
   [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.exists(ZooKeeper.java:1041)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient$4.execute(SolrZkClient.java:225)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient$4.execute(SolrZkClient.java:222)
   [junit4]   2> 	at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient.exists(SolrZkClient.java:222)
   [junit4]   2> 	at org.apache.solr.cloud.OverseerCollectionProcessor.prioritizeOverseerNodes(OverseerCollectionProcessor.java:234)
   [junit4]   2> 	at org.apache.solr.cloud.OverseerCollectionProcessor.run(OverseerCollectionProcessor.java:185)
   [junit4]   2> 	at java.lang.Thread.run(Thread.java:744)
   [junit4]   2> 
   [junit4]   2> 2555244 T6406 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:65291_solr
   [junit4]   2> 2555245 T6406 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
   [junit4]   2> 2555250 T6406 oasc.Overseer.start Overseer (id=91393847154769925-127.0.0.1:65291_solr-n_0000000001) starting
   [junit4]   2> 2555260 T6416 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
   [junit4]   2> 2555263 T6416 oasc.OverseerCollectionProcessor.prioritizeOverseerNodes prioritizing overseer nodes
   [junit4]   2> 2555264 T6415 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
   [junit4]   2> 2555268 T6415 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 2555269 T6415 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"state1",
   [junit4]   2> 	  "node_name":"node1",
   [junit4]   2> 	  "core":"core1",
   [junit4]   2> 	  "core_node_name":"node1",
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "numShards":"1",
   [junit4]   2> 	  "base_url":"http://node1/solr/"}
   [junit4]   2> 2555269 T6415 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1]
   [junit4]   2> 2555269 T6415 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
   [junit4]   2> 2555277 T6414 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2555278 T6409 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> 2555852 T6326 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
   [junit4]   2> 2555878 T6326 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 2555890 T6414 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2555896 T6414 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2555896 T6415 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 2555896 T6326 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
   [junit4]   2> 2555908 T6415 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"state2",
   [junit4]   2> 	  "node_name":"node1",
   [junit4]   2> 	  "core":"core1",
   [junit4]   2> 	  "core_node_name":"node1",
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "numShards":"1",
   [junit4]   2> 	  "base_url":"http://node1/solr/"}
   [junit4]   2> 2555908 T6415 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
   [junit4]   2> 2555915 T6414 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2555918 T6326 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 2555923 T6418 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@29f44041 name:ZooKeeperConnection Watcher:127.0.0.1:65291/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 2555924 T6326 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 2555928 T6326 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 2555933 T6326 oascc.SolrZkClient.makePath makePath: /live_nodes/node2
   [junit4]   2> 2555938 T6409 oascc.ZkStateReader$3.process Updating live nodes... (2)
   [junit4]   2> 2555939 T6418 oascc.ZkStateReader$3.process Updating live nodes... (2)
   [junit4]   2> 2555944 T6414 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2555944 T6326 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
   [junit4]   2> 2555948 T6415 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"state1",
   [junit4]   2> 	  "node_name":"node1",
   [junit4]   2> 	  "core":"core1",
   [junit4]   2> 	  "core_node_name":"node1",
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "numShards":"1",
   [junit4]   2> 	  "base_url":"http://node1/solr/"}
   [junit4]   2> 2555948 T6415 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
   [junit4]   2> 2555957 T6414 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2555966 T6326 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 2556092 T6418 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
   [junit4]   2> 2556093 T6409 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
   [junit4]   2> 2556226 T6326 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 2556234 T6414 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2556235 T6414 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2556235 T6414 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2556238 T6415 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 2556239 T6415 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"state2",
   [junit4]   2> 	  "node_name":"node2",
   [junit4]   2> 	  "core":"core4",
   [junit4]   2> 	  "core_node_name":"node2",
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "numShards":"1",
   [junit4]   2> 	  "base_url":"http://node2/solr/"}
   [junit4]   2> 2556239 T6415 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=1
   [junit4]   2> 2556239 T6415 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
   [junit4]   2> 2556245 T6414 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2556381 T6409 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
   [junit4]   2> 25563

[...truncated too long message...]

th:/clusterstate.json, has occurred - updating... (live nodes size: 1)
   [junit4]   2> 2589822 T6792 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> 2589823 T6326 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 2589827 T6787 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x144b238c4be0004, likely client has closed socket
   [junit4]   2> 	at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:220)
   [junit4]   2> 	at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208)
   [junit4]   2> 	at java.lang.Thread.run(Thread.java:744)
   [junit4]   2> 
   [junit4]   2> 2589830 T6792 oascc.ZkStateReader$3.process Updating live nodes... (0)
   [junit4]   2> 2589830 T6804 oascc.ZkStateReader$3.process Updating live nodes... (0)
   [junit4]   2> 2589831 T6787 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x144b238c4be0005, likely client has closed socket
   [junit4]   2> 	at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:220)
   [junit4]   2> 	at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208)
   [junit4]   2> 	at java.lang.Thread.run(Thread.java:744)
   [junit4]   2> 
   [junit4]   2> 2589834 T6787 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x144b238c4be0000, likely client has closed socket
   [junit4]   2> 	at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:220)
   [junit4]   2> 	at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208)
   [junit4]   2> 	at java.lang.Thread.run(Thread.java:744)
   [junit4]   2> 
   [junit4]   2> 2589838 T6326 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:49309 49309
   [junit4]   2> 2591237 T6801 oasc.Overseer$ClusterStateUpdater.run WARN Solr cannot talk to ZK, exiting Overseer main queue loop org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /overseer/queue-work
   [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:1468)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:259)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:256)
   [junit4]   2> 	at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient.getChildren(SolrZkClient.java:256)
   [junit4]   2> 	at org.apache.solr.cloud.DistributedQueue.orderedChildren(DistributedQueue.java:89)
   [junit4]   2> 	at org.apache.solr.cloud.DistributedQueue.remove(DistributedQueue.java:160)
   [junit4]   2> 	at org.apache.solr.cloud.DistributedQueue.poll(DistributedQueue.java:445)
   [junit4]   2> 	at org.apache.solr.cloud.Overseer$ClusterStateUpdater.run(Overseer.java:224)
   [junit4]   2> 	at java.lang.Thread.run(Thread.java:744)
   [junit4]   2> 
   [junit4]   2> 2591961 T6326 oas.SolrTestCaseJ4.tearDown ###Ending testDoubleAssignment
   [junit4]   1> client port:0.0.0.0/0.0.0.0:0
   [junit4]   2> 2591964 T6326 oas.SolrTestCaseJ4.initCore ####initCore
   [junit4]   2> 2591964 T6326 oas.SolrTestCaseJ4.initCore ####initCore end
   [junit4]   2> 2594761 T6326 oas.SolrTestCaseJ4.deleteCore ###deleteCore
   [junit4]   2> NOTE: test params are: codec=Lucene46: {}, docValues:{}, sim=DefaultSimilarity, locale=ja_JP_JP_#u-ca-japanese, timezone=Etc/GMT-9
   [junit4]   2> NOTE: Windows 7 6.1 amd64/Oracle Corporation 1.7.0_51 (64-bit)/cpus=2,threads=1,free=116576600,total=536870912
   [junit4]   2> NOTE: All tests run in this JVM: [OverseerCollectionProcessorTest, QueryResultKeyTest, PolyFieldTest, TestIndexSearcher, TestSweetSpotSimilarityFactory, TestStressRecovery, PreAnalyzedUpdateProcessorTest, CurrencyFieldOpenExchangeTest, UnloadDistributedZkTest, MBeansHandlerTest, TestJmxIntegration, SolrXmlInZkTest, BlockDirectoryTest, TestPhraseSuggestions, ZkControllerTest, TestStressLucene, SuggesterWFSTTest, TestMergePolicyConfig, StandardRequestHandlerTest, SynonymTokenizerTest, HighlighterConfigTest, TestSerializedLuceneMatchVersion, SliceStateTest, ZkNodePropsTest, DistributedQueryElevationComponentTest, DocValuesTest, TestRemoteStreaming, BlockCacheTest, FastVectorHighlighterTest, TestCollationFieldDocValues, DisMaxRequestHandlerTest, TestCharFilters, TestJoin, DocValuesMissingTest, OpenExchangeRatesOrgProviderTest, TermVectorComponentDistributedTest, TestZkChroot, CursorMarkTest, TestExpandComponent, QueryParsingTest, TestReversedWildcardFilterFactory, TestQueryTypes, TestSolrXmlPersistor, AnalysisAfterCoreReloadTest, DistributedQueryComponentOptimizationTest, AssignTest, SystemInfoHandlerTest, SyncSliceTest, EnumFieldTest, TestRTGBase, TestDistributedGrouping, TestSolrDeletionPolicy1, HdfsBasicDistributedZk2Test, TestBinaryResponseWriter, TestFoldingMultitermQuery, TimeZoneUtilsTest, TestDocumentBuilder, SOLR749Test, TestUniqueKeyFieldResource, SpellingQueryConverterTest, TestDynamicFieldCollectionResource, UUIDFieldTest, TestCloudManagedSchema, SimpleFacetsTest, SpellCheckCollatorTest, CacheHeaderTest, TestNRTOpen, ChangedSchemaMergeTest, CircularListTest, TestAnalyzeInfixSuggestions, ParsingFieldUpdateProcessorsTest, EchoParamsTest, ExternalFileFieldSortTest, TestManagedSchema, RequestHandlersTest, AlternateDirectoryTest, ChaosMonkeyNothingIsSafeTest, SuggesterFSTTest, RemoteQueryErrorTest, BJQParserTest, OpenCloseCoreStressTest, DateFieldTest, JSONWriterTest, TestCSVResponseWriter, TestLMJelinekMercerSimilarityFactory, DistributedSuggestComponentTest, PrimUtilsTest, AutoCommitTest, TestSolrXml, FunctionTest, WordBreakSolrSpellCheckerTest, TestBadConfig, HardAutoCommitTest, URLClassifyProcessorTest, DistributedSpellCheckComponentTest, FileUtilsTest, SolrCmdDistributorTest, TestUpdate, StatelessScriptUpdateProcessorFactoryTest, LeaderElectionTest, HdfsRecoveryZkTest, ChaosMonkeySafeLeaderTest, TestInitQParser, MinimalSchemaTest, FieldMutatingUpdateProcessorTest, TestDFRSimilarityFactory, XsltUpdateRequestHandlerTest, ShowFileRequestHandlerTest, CoreMergeIndexesAdminHandlerTest, TestCSVLoader, TestBlendedInfixSuggestions, DeleteShardTest, TestFastWriter, TestSearchPerf, NumericFieldsTest, TestCollationField, TestInfoStreamLogging, BadCopyFieldTest, TestQuerySenderListener, BinaryUpdateRequestHandlerTest, TestCursorMarkWithoutUniqueKey, TestWordDelimiterFilterFactory, DistribCursorPagingTest, RangeFacetTest, DocumentAnalysisRequestHandlerTest, TestPHPSerializedResponseWriter, NotRequiredUniqueKeyTest, HdfsDirectoryTest, PingRequestHandlerTest, DocValuesMultiTest, TestPostingsSolrHighlighter, TestCollapseQParserPlugin, PathHierarchyTokenizerFactoryTest, SolrTestCaseJ4Test, FullSolrCloudDistribCmdsTest, SimplePostToolTest, LukeRequestHandlerTest, FileBasedSpellCheckerTest, TestFunctionQuery, TestShardHandlerFactory, TestQueryUtils, TestCloudManagedSchemaAddField, TestLRUCache, QueryEqualityTest, CurrencyFieldXmlFileTest, TestLMDirichletSimilarityFactory, TestCoreContainer, BasicDistributedZkTest, TermVectorComponentTest, TestLazyCores, OverseerRolesTest, AliasIntegrationTest, DistributedQueryComponentCustomSortTest, TestStressReorder, TestDefaultSearchFieldResource, CoreContainerCoreInitFailuresTest, TestAddFieldRealTimeGet, TestTrie, BadComponentTest, TestPseudoReturnFields, TestDistribDocBasedVersion, TestRealTimeGet, StressHdfsTest, TestSolrQueryParser, TestMaxScoreQueryParser, TestSolrXmlPersistence, FieldAnalysisRequestHandlerTest, RequiredFieldsTest, CoreAdminHandlerTest, TestClassNameShortening, TestNumberUtils, TestDistributedMissingSort, IndexBasedSpellCheckerTest, SampleTest, TestHighFrequencyDictionaryFactory, TestLFUCache, TestSort, TestExtendedDismaxParser, TestReloadAndDeleteDocs, SuggesterTSTTest, BasicDistributedZk2Test, CollectionsAPIDistributedZkTest, OverseerTest]
   [junit4] Completed in 81.77s, 9 tests, 1 error <<< FAILURES!

[...truncated 608 lines...]
BUILD FAILED
C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\build.xml:467: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\build.xml:447: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\build.xml:45: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\extra-targets.xml:37: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build.xml:189: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\common-build.xml:490: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\lucene\common-build.xml:1275: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\lucene\common-build.xml:907: There were test failures: 379 suites, 1622 tests, 1 error, 54 ignored (33 assumptions)

Total time: 98 minutes 30 seconds
Build step 'Invoke Ant' marked build as failure
Description set: Java: 64bit/jdk1.7.0_51 -XX:+UseCompressedOops -XX:+UseG1GC -XX:-UseSuperWord
Archiving artifacts
Recording test results
Email was triggered for: Failure
Sending email for trigger: Failure



Mime
View raw message