You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@lucene.apache.org by Policeman Jenkins Server <je...@thetaphi.de> on 2014/03/04 00:31:20 UTC

[JENKINS] Lucene-Solr-4.x-Linux (32bit/jdk1.7.0_60-ea-b04) - Build # 9558 - Failure!

Build: http://jenkins.thetaphi.de/job/Lucene-Solr-4.x-Linux/9558/
Java: 32bit/jdk1.7.0_60-ea-b04 -client -XX:+UseG1GC

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([CD4DE213ABC199B4:C9456DE0B9647695]: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:154)
	at org.apache.solr.cloud.OverseerTest.testOverseerFailure(OverseerTest.java:593)
	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:1559)
	at com.carrotsearch.randomizedtesting.RandomizedRunner.access$600(RandomizedRunner.java:79)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:737)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:773)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:787)
	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:358)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:782)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:442)
	at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:746)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:648)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:682)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:693)
	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:358)
	at java.lang.Thread.run(Thread.java:744)
Caused by: org.apache.solr.common.SolrException: org.apache.zookeeper.KeeperException$NodeExistsException: KeeperErrorCode = NodeExists for /collections/collection1/leaders/shard1
	at org.apache.solr.common.util.RetryUtil.retryOnThrowable(RetryUtil.java:40)
	at org.apache.solr.cloud.ShardLeaderElectionContextBase.runLeaderProcess(ElectionContext.java:122)
	... 46 more
Caused by: org.apache.zookeeper.KeeperException$NodeExistsException: KeeperErrorCode = NodeExists for /collections/collection1/leaders/shard1
	at org.apache.zookeeper.KeeperException.create(KeeperException.java:119)
	at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
	at org.apache.zookeeper.ZooKeeper.create(ZooKeeper.java:783)
	at org.apache.solr.common.cloud.SolrZkClient$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:34)
	... 47 more




Build Log:
[...truncated 10895 lines...]
   [junit4] Suite: org.apache.solr.cloud.OverseerTest
   [junit4]   2> 807615 T3227 oas.SolrTestCaseJ4.buildSSLConfig Randomized ssl (true) and clientAuth (true)
   [junit4]   2> 807615 T3227 oas.SolrTestCaseJ4.initCore ####initCore
   [junit4]   2> Creating dataDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./solrtest-OverseerTest-1393888996482
   [junit4]   2> 807616 T3227 oas.SolrTestCaseJ4.initCore ####initCore end
   [junit4]   2> 807618 T3227 oas.SolrTestCaseJ4.setUp ###Starting testPlaceholders
   [junit4]   2> 807619 T3227 oasc.ZkTestServer.run STARTING ZK TEST SERVER
   [junit4]   2> 807620 T3228 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
   [junit4]   2> 807720 T3227 oasc.ZkTestServer.run start zk server on port:39812
   [junit4]   2> 807721 T3227 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 807897 T3234 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1fc53cc name:ZooKeeperConnection Watcher:127.0.0.1:39812/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 807897 T3227 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 807898 T3227 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 807900 T3236 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1d57618 name:ZooKeeperConnection Watcher:127.0.0.1:39812 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 807901 T3227 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 807903 T3227 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 807904 T3238 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1af5439 name:ZooKeeperConnection Watcher:127.0.0.1:39812 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 807905 T3227 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 807905 T3227 oascc.SolrZkClient.makePath makePath: /solr
   [junit4]   2> 807908 T3227 oascc.SolrZkClient.makePath makePath: /live_nodes
   [junit4]   2> 807910 T3227 oascc.SolrZkClient.makePath makePath: /clusterstate.json
   [junit4]   2> 807912 T3227 oascc.SolrZkClient.makePath makePath: /aliases.json
   [junit4]   2> 807914 T3227 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 807917 T3227 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 807919 T3240 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@13edb21 name:ZooKeeperConnection Watcher:127.0.0.1:39812/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 807920 T3227 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 807921 T3227 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 807923 T3227 oascc.SolrZkClient.makePath makePath: /live_nodes/node1
   [junit4]   2> 807925 T3234 oascc.ZkStateReader$3.process Updating live nodes... (1)
   [junit4]   2> 807925 T3240 oascc.ZkStateReader$3.process Updating live nodes... (1)
   [junit4]   2> 807926 T3227 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 807927 T3242 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@3b156 name:ZooKeeperConnection Watcher:127.0.0.1:39812/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 807927 T3227 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 807928 T3227 oascc.SolrZkClient.makePath makePath: /overseer_elect
   [junit4]   2> 807930 T3227 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
   [junit4]   2> 807932 T3227 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:39812_solr
   [junit4]   2> 807933 T3227 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
   [junit4]   2> 807934 T3227 oasc.Overseer.start Overseer (id=91349909273837572-127.0.0.1:39812_solr-n_0000000000) starting
   [junit4]   2> 807935 T3227 oascc.SolrZkClient.makePath makePath: /overseer/queue
   [junit4]   2> 807937 T3227 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
   [junit4]   2> 807939 T3227 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
   [junit4]   2> 807941 T3244 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
   [junit4]   2> 807942 T3244 oasc.OverseerCollectionProcessor.prioritizeOverseerNodes prioritizing overseer nodes
   [junit4]   2> 807942 T3243 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
   [junit4]   2> 807944 T3243 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 807944 T3243 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=12 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"recovering",
   [junit4]   2> 	  "node_name":"node1",
   [junit4]   2> 	  "core":"core1",
   [junit4]   2> 	  "core_node_name":"node1",
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "numShards":"12",
   [junit4]   2> 	  "base_url":"http://node1/solr/"}
   [junit4]   2> 807944 T3243 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1, shard2, shard3, shard4, shard5, shard6, shard7, shard8, shard9, shard10, shard11, shard12]
   [junit4]   2> 807945 T3243 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
   [junit4]   2> 807946 T3242 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 807965 T3234 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> 807965 T3240 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> 808443 T3227 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
   [junit4]   2> 808450 T3227 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 808455 T3242 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 808455 T3227 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 808457 T3243 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 808459 T3234 oascc.ZkStateReader$3.process Updating live nodes... (0)
   [junit4]   2> 808459 T3240 oascc.ZkStateReader$3.process Updating live nodes... (0)
   [junit4]   2> 808461 T3227 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:39812 39812
   [junit4]   2> 808593 T3227 oas.SolrTestCaseJ4.tearDown ###Ending testPlaceholders
   [junit4]   1> client port:0.0.0.0/0.0.0.0:0
   [junit4]   2> 808600 T3227 oas.SolrTestCaseJ4.setUp ###Starting testOverseerFailure
   [junit4]   2> 808600 T3227 oasc.ZkTestServer.run STARTING ZK TEST SERVER
   [junit4]   2> 808601 T3245 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
   [junit4]   2> 808701 T3227 oasc.ZkTestServer.run start zk server on port:52414
   [junit4]   2> 808702 T3227 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 808704 T3251 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@b482cd name:ZooKeeperConnection Watcher:127.0.0.1:52414 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 808704 T3227 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 808722 T3227 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 808723 T3253 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@c729f4 name:ZooKeeperConnection Watcher:127.0.0.1:52414 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 808723 T3227 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 808724 T3227 oascc.SolrZkClient.makePath makePath: /solr
   [junit4]   2> 808726 T3227 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 808727 T3255 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@6a8a4c name:ZooKeeperConnection Watcher:127.0.0.1:52414/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 808727 T3227 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 808728 T3227 oascc.SolrZkClient.makePath makePath: /live_nodes
   [junit4]   2> 808730 T3227 oascc.SolrZkClient.makePath makePath: /clusterstate.json
   [junit4]   2> 808731 T3227 oascc.SolrZkClient.makePath makePath: /aliases.json
   [junit4]   2> 808732 T3227 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 808734 T3227 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 808735 T3257 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@323a7c name:ZooKeeperConnection Watcher:127.0.0.1:52414/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 808735 T3227 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 808736 T3227 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 808738 T3227 oascc.SolrZkClient.makePath makePath: /live_nodes/node1
   [junit4]   2> 808740 T3257 oascc.ZkStateReader$3.process Updating live nodes... (1)
   [junit4]   2> 808740 T3227 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 808740 T3255 oascc.ZkStateReader$3.process Updating live nodes... (1)
   [junit4]   2> 808741 T3259 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1e7fa37 name:ZooKeeperConnection Watcher:127.0.0.1:52414/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 808741 T3227 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 808742 T3227 oascc.SolrZkClient.makePath makePath: /overseer_elect
   [junit4]   2> 808744 T3227 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
   [junit4]   2> 808746 T3227 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:52414_solr
   [junit4]   2> 808747 T3227 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
   [junit4]   2> 808748 T3227 oasc.Overseer.start Overseer (id=91349909338193924-127.0.0.1:52414_solr-n_0000000000) starting
   [junit4]   2> 808750 T3227 oascc.SolrZkClient.makePath makePath: /overseer/queue
   [junit4]   2> 808752 T3227 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
   [junit4]   2> 808757 T3227 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
   [junit4]   2> 808760 T3261 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
   [junit4]   2> 808760 T3261 oasc.OverseerCollectionProcessor.prioritizeOverseerNodes prioritizing overseer nodes
   [junit4]   2> 808760 T3260 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
   [junit4]   2> 809762 T3259 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 809764 T3260 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 809764 T3260 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> 809764 T3260 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1]
   [junit4]   2> 809765 T3260 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
   [junit4]   2> 809767 T3259 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 809767 T3255 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> 809767 T3257 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> 810262 T3227 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
   [junit4]   2> 810277 T3227 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 810286 T3259 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 810288 T3227 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 810290 T3260 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 810293 T3259 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 810293 T3227 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
   [junit4]   2> 810296 T3260 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> 810297 T3260 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
   [junit4]   2> 810301 T3259 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 810403 T3257 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> 810403 T3255 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> 811459 T3227 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
   [junit4]   2> 811469 T3227 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 811471 T3263 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1305ba9 name:ZooKeeperConnection Watcher:127.0.0.1:52414/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 811471 T3227 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 811479 T3227 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:52414_solr
   [junit4]   2> 811479 T3227 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
   [junit4]   2> 811483 T3227 oasc.Overseer.start Overseer (id=91349909338193925-127.0.0.1:52414_solr-n_0000000001) starting
   [junit4]   2> 811490 T3265 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
   [junit4]   2> 811492 T3265 oasc.OverseerCollectionProcessor.prioritizeOverseerNodes prioritizing overseer nodes
   [junit4]   2> 811492 T3264 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
   [junit4]   2> 811496 T3264 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 811497 T3264 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> 811498 T3264 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
   [junit4]   2> 811502 T3263 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 811504 T3255 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> 811504 T3257 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> 811559 T3263 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 811559 T3227 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
   [junit4]   2> 811561 T3264 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 811571 T3227 oasc.LeaderElector.checkIfIamLeader WARN Failed setting watch org.apache.zookeeper.KeeperException$NoNodeException: KeeperErrorCode = NoNode for /collections/collection1/leader_elect/shard1/election/91349909338193923-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:154)
   [junit4]   2> 	at org.apache.solr.cloud.OverseerTest.testOverseerFailure(OverseerTest.java:593)
   [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:1559)
   [junit4]   2> 	at com.carrotsearch.randomizedtesting.RandomizedRunner.access$600(RandomizedRunner.java:79)
   [junit4]   2> 	at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:737)
   [junit4]   2> 	at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:773)
   [junit4]   2> 	at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:787)
   [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:358)
   [junit4]   2> 	at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:782)
   [junit4]   2> 	at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:442)
   [junit4]   2> 	at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:746)
   [junit4]   2> 	at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:648)
   [junit4]   2> 	at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:682)
   [junit4]   2> 	at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:693)
   [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:358)
   [junit4]   2> 	at java.lang.Thread.run(Thread.java:744)
   [junit4]   2> 
   [junit4]   2> 811575 T3257 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 811578 T3227 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 811581 T3264 oasc.SolrException.log ERROR Problem cleaning up collection in zk:collection1:org.apache.zookeeper.KeeperException$NotEmptyException: KeeperErrorCode = Directory not empty for /collections/collection1
   [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.cloud.Overseer$ClusterStateUpdater.removeCore(Overseer.java:950)
   [junit4]   2> 		at org.apache.solr.cloud.Overseer$ClusterStateUpdater.processMessage(Overseer.java:236)
   [junit4]   2> 		at org.apache.solr.cloud.Overseer$ClusterStateUpdater.run(Overseer.java:193)
   [junit4]   2> 		at java.lang.Thread.run(Thread.java:744)
   [junit4]   2> 	
   [junit4]   2> 811585 T3263 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 811587 T3263 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 811589 T3257 oasc.LeaderElector$1.process WARN  org.apache.zookeeper.KeeperException$NoNodeException: KeeperErrorCode = NoNode for /collections/collection1/leader_elect/shard1/election
   [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.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> 811589 T3264 oasc.Overseer$ClusterStateUpdater.setShardLeader ERROR Could not mark shard leader for non existing collection:collection1
   [junit4]   2> 811594 T3263 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 811697 T3255 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> 811697 T3257 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> 812585 T3227 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 813588 T3227 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 814592 T3227 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 815597 T3227 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 816603 T3227 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 817608 T3227 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 818612 T3227 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 819615 T3227 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 820620 T3227 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 821625 T3227 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 822629 T3227 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 823634 T3227 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 824637 T3227 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 825641 T3227 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 826646 T3227 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 826654 T3257 oascc.ZkStateReader$3.process Updating live nodes... (0)
   [junit4]   2> 826654 T3255 oascc.ZkStateReader$3.process Updating live nodes... (0)
   [junit4]   2> 826661 T3227 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:52414 52414
   [junit4]   2> 827191 T3227 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=CD4DE213ABC199B4 -Dtests.multiplier=3 -Dtests.slow=true -Dtests.locale=de -Dtests.timezone=Asia/Pyongyang -Dtests.file.encoding=US-ASCII
   [junit4] ERROR   18.6s J1 | OverseerTest.testOverseerFailure <<<
   [junit4]    > Throwable #1: org.apache.solr.common.SolrException: Could not register as the leader because creating the ephemeral registration node in ZooKeeper failed
   [junit4]    > 	at __randomizedtesting.SeedInfo.seed([CD4DE213ABC199B4:C9456DE0B9647695]: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:154)
   [junit4]    > 	at org.apache.solr.cloud.OverseerTest.testOverseerFailure(OverseerTest.java:593)
   [junit4]    > 	at java.lang.Thread.run(Thread.java:744)
   [junit4]    > Caused by: org.apache.solr.common.SolrException: org.apache.zookeeper.KeeperException$NodeExistsException: KeeperErrorCode = NodeExists for /collections/collection1/leaders/shard1
   [junit4]    > 	at org.apache.solr.common.util.RetryUtil.retryOnThrowable(RetryUtil.java:40)
   [junit4]    > 	at org.apache.solr.cloud.ShardLeaderElectionContextBase.runLeaderProcess(ElectionContext.java:122)
   [junit4]    > 	... 46 more
   [junit4]    > Caused by: org.apache.zookeeper.KeeperException$NodeExistsException: KeeperErrorCode = NodeExists for /collections/collection1/leaders/shard1
   [junit4]    > 	at org.apache.zookeeper.KeeperException.create(KeeperException.java:119)
   [junit4]    > 	at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
   [junit4]    > 	at org.apache.zookeeper.ZooKeeper.create(ZooKeeper.java:783)
   [junit4]    > 	at org.apache.solr.common.cloud.SolrZkClient$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:34)
   [junit4]    > 	... 47 more
   [junit4]   2> 827217 T3227 oas.SolrTestCaseJ4.setUp ###Starting testShardLeaderChange
   [junit4]   2> 827217 T3227 oasc.ZkTestServer.run STARTING ZK TEST SERVER
   [junit4]   2> 827217 T3266 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
   [junit4]   2> 827318 T3227 oasc.ZkTestServer.run start zk server on port:48045
   [junit4]   2> 827319 T3227 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 827322 T3272 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@516bc9 name:ZooKeeperConnection Watcher:127.0.0.1:48045/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 827323 T3227 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 827324 T3227 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 827326 T3274 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@4a74ce name:ZooKeeperConnection Watcher:127.0.0.1:48045 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 827326 T3227 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 827352 T3227 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 827354 T3276 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@142ed30 name:ZooKeeperConnection Watcher:127.0.0.1:48045 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 827354 T3227 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 827355 T3227 oascc.SolrZkClient.makePath makePath: /solr
   [junit4]   2> 827359 T3227 oascc.SolrZkClient.makePath makePath: /live_nodes
   [junit4]   2> 827365 T3277 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 827365 T3227 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 827367 T3280 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@65d56c name:ZooKeeperConnection Watcher:127.0.0.1:48045/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 827368 T3281 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@fcb365 name:ZooKeeperConnection Watcher:127.0.0.1:48045/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 827368 T3277 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 827368 T3227 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 827370 T3277 oascc.SolrZkClient.makePath makePath: /overseer_elect
   [junit4]   2> 827371 T3227 oascc.SolrZkClient.makePath makePath: /clusterstate.json
   [junit4]   2> 827374 T3277 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
   [junit4]   2> 827375 T3227 oascc.SolrZkClient.makePath makePath: /aliases.json
   [junit4]   2> 827379 T3227 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 827381 T3277 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:48045_solr
   [junit4]   2> 827381 T3277 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
   [junit4]   2> 827383 T3227 oascc.SolrZkClient.makePath makePath: /live_nodes/node1
   [junit4]   2> 827385 T3277 oasc.Overseer.start Overseer (id=91349910558539779-127.0.0.1:48045_solr-n_0000000000) starting
   [junit4]   2> 827389 T3281 oascc.ZkStateReader$3.process Updating live nodes... (1)
   [junit4]   2> 827390 T3277 oascc.SolrZkClient.makePath makePath: /overseer/queue
   [junit4]   2> 827391 T3227 oascc.SolrZkClient.makePath makePath: /overseer/queue
   [junit4]   2> 827395 T3277 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
   [junit4]   2> 827402 T3277 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
   [junit4]   2> 827407 T3283 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
   [junit4]   2> 827407 T3277 oasc.OverseerTest$OverseerRestarter.run Killing overseer.
   [junit4]   2> 827408 T3283 oasc.OverseerCollectionProcessor.prioritizeOverseerNodes prioritizing overseer nodes
   [junit4]   2> 827408 T3282 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
   [junit4]   2> 827409 T3282 oasc.Overseer$ClusterStateUpdater.amILeader  org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /overseer_elect/leader
   [junit4]   2> 	at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
   [junit4]   2> 	at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
   [junit4]   2> 	at org.apache.zookeeper.ZooKeeper.getData(ZooKeeper.java: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.Overseer$ClusterStateUpdater.amILeader(Overseer.java:450)
   [junit4]   2> 	at org.apache.solr.cloud.Overseer$ClusterStateUpdater.run(Overseer.java:159)
   [junit4]   2> 	at java.lang.Thread.run(Thread.java:744)
   [junit4]   2> 
   [junit4]   2> 827410 T3277 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 827410 T3282 oasc.Overseer$ClusterStateUpdater.amILeader According to ZK I (id=91349910558539779-127.0.0.1:48045_solr-n_0000000000) am no longer a leader.
   [junit4]   2> 827412 T3285 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@29ce18 name:ZooKeeperConnection Watcher:127.0.0.1:48045/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 827413 T3277 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 827413 T3283 oasc.OverseerCollectionProcessor.run ERROR Unable to prioritize overseer  java.lang.InterruptedException: sleep interrupted
   [junit4]   2> 	at java.lang.Thread.sleep(Native Method)
   [junit4]   2> 	at org.apache.solr.common.cloud.ZkCmdExecutor.retryDelay(ZkCmdExecutor.java:119)
   [junit4]   2> 	at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:87)
   [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> 827414 T3283 oasc.OverseerCollectionProcessor.amILeader  org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /overseer_elect/leader
   [junit4]   2> 	at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
   [junit4]   2> 	at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
   [junit4]   2> 	at org.apache.zookeeper.ZooKeeper.getData(ZooKeeper.java: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.OverseerCollectionProcessor.amILeader(OverseerCollectionProcessor.java:362)
   [junit4]   2> 	at org.apache.solr.cloud.OverseerCollectionProcessor.run(OverseerCollectionProcessor.java:192)
   [junit4]   2> 	at java.lang.Thread.run(Thread.java:744)
   [junit4]   2> 
   [junit4]   2> 827415 T3283 oasc.OverseerCollectionProcessor.amILeader According to ZK I (id=91349910558539779-127.0.0.1:48045_solr-n_0000000000) am no longer a leader.
   [junit4]   2> 827418 T3277 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:48045_solr
   [junit4]   2> 827418 T3277 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
   [junit4]   2> 827422 T3277 oasc.Overseer.start Overseer (id=91349910558539781-127.0.0.1:48045_solr-n_0000000001) starting
   [junit4]   2> 827429 T3287 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
   [junit4]   2> 827430 T3287 oasc.OverseerCollectionProcessor.prioritizeOverseerNodes prioritizing overseer nodes
   [junit4]   2> 827430 T3286 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
   [junit4]   2> 827433 T3286 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 827434 T3286 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> 827434 T3286 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1]
   [junit4]   2> 827435 T3286 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
   [junit4]   2> 827440 T3285 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 827441 T3281 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> 827896 T3227 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
   [junit4]   2> 827904 T3227 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 827908 T3285 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 827910 T3285 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 827910 T3286 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 827910 T3227 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
   [junit4]   2> 827914 T3286 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> 827914 T3286 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
   [junit4]   2> 827916 T3227 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 827917 T3285 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 827917 T3289 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1214e6b name:ZooKeeperConnection Watcher:127.0.0.1:48045/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 827918 T3227 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 827920 T3227 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 827922 T3227 oascc.SolrZkClient.makePath makePath: /live_nodes/node2
   [junit4]   2> 827924 T3281 oascc.ZkStateReader$3.process Updating live nodes... (2)
   [junit4]   2> 827924 T3289 oascc.ZkStateReader$3.process Updating live nodes... (2)
   [junit4]   2> 827926 T3285 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 827926 T3227 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
   [junit4]   2> 827927 T3286 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> 827927 T3286 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
   [junit4]   2> 827929 T3285 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 827931 T3227 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 828032 T3289 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> 828032 T3281 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> 828133 T3227 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 828138 T3285 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 828138 T3285 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 828138 T3285 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 828139 T3286 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 828140 T3286 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> 828140 T3286 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=1
   [junit4]   2> 828140 T3286 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
   [junit4]   2> 828143 T3285 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 828246 T3281 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> 828246 T3289 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> 828638 T3227 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
   [junit4]   2> 828645 T3289 oascc.ZkStateReader$3.process Updating live nodes... (1)
   [junit4]   2> 828645 T3281 oascc.ZkStateReader$3.process Updating live nodes... (1)
   [junit4]   2> 828646 T3281 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> 828646 T3227 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 828647 T3289 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 828647 T3281 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> 828652 T3285 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 828652 T3285 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 828652 T3285 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 828653 T3286 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 828656 T3285 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 828758 T3289 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> 828849 T3227 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 828851 T3227 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 828852 T3291 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@10327eb name:ZooKeeperConnection Watcher:127.0.0.1:48045/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 828852 T3227 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 828854 T3227 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 828857 T3227 oascc.SolrZkClient.makePath makePath: /live_nodes/node1
   [junit4]   2> 828859 T3289 oascc.ZkStateReader$3.process Updating live nodes... (2)
   [junit4]   2> 828859 T3291 oascc.ZkStateReader$3.process Updating live nodes... (2)
   [junit4]   2> 828860 T3227 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
   [junit4]   2> 828860 T3285 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 828861 T3285 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 828861 T3285 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 828862 T3286 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 828863 T3286 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> 828863 T3286 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
   [junit4]   2> 828865 T3285 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 828865 T3289 oascc.ZkStateReader$3.process Updating live nodes... (1)
   [junit4]   2> 828865 T3291 oascc.ZkStateReader$3.process Updating live nodes... (1)
   [junit4]   2> 828869 T3291 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 828870 T3285 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 828870 T3227 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
   [junit4]   2> 828871 T3286 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> 828872 T3286 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
   [junit4]   2> 828874 T3285 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 828876 T3227 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 828877 T3293 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1ca531 name:ZooKeeperConnection Watcher:127.0.0.1:48045/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 828877 T3285 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 828877 T3227 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 828879 T3227 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 828880 T3227 oascc.SolrZkClient.makePath makePath: /live_nodes/node2
   [junit4]   2> 828882 T3293 oascc.ZkStateReader$3.process Updating live nodes... (2)
   [junit4]   2> 828882 T3291 oascc.ZkStateReader$3.process Updating live nodes... (2)
   [junit4]   2> 828883 T3227 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
   [junit4]   2> 828883 T3285 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 828884 T3286 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> 828885 T3286 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
   [junit4]   2> 828887 T3285 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 828887 T3227 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 828931 T3277 oasc.OverseerTest$OverseerRestarter.run Killing overseer.
   [junit4]   2> 828933 T3277 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 828935 T3295 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@41fa39 name:ZooKeeperConnection Watcher:127.0.0.1:48045/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 828935 T3277 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 828938 T3277 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:48045_solr
   [junit4]   2> 828938 T3277 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
   [junit4]   2> 828940 T3277 oasc.Overseer.start Overseer (id=91349910558539785-127.0.0.1:48045_solr-n_0000000002) starting
   [junit4]   2> 828942 T3297 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
   [junit4]   2> 828943 T3297 oasc.OverseerCollectionProcessor.prioritizeOverseerNodes prioritizing overseer nodes
   [junit4]   2> 828944 T3296 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 828944 T3296 oasc.Overseer$ClusterStateUpdater.run Replaying operations from work queue.
   [junit4]   2> 828945 T3296 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> 828945 T3296 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
   [junit4]   2> 828946 T3293 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> 828946 T3291 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> 828948 T3296 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> 828948 T3296 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
   [junit4]   2> 828949 T3291 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> 828949 T3293 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> 828952 T3293 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> 828952 T3291 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> 828955 T3296 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> 828955 T3296 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
   [junit4]   2> 828956 T3291 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> 828956 T3293 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> 828958 T3296 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
   [junit4]   2> 829089 T3227 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 829093 T3295 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 829093 T3227 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
   [junit4]   2> 829095 T3296 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 829095 T3296 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> 829096 T3296 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
   [junit4]   2> 829100 T3295 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 829101 T3293 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> 829101 T3291 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> 829103 T3293 oascc.ZkStateReader$3.process Updating live nodes... (1)
   [junit4]   2> 829105 T3227 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 829107 T3293 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 829113 T3295 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 829116 T3296 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 829119 T3295 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 829222 T3293 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> 829308 T3227 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 829309 T3227 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 829310 T3299 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@11dd948 name:ZooKeeperConnection Watcher:127.0.0.1:48045/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 829311 T3227 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 829312 T3227 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 829314 T3227 oascc.SolrZkClient.makePath makePath: /live_nodes/node1
   [junit4]   2> 829318 T3299 oascc.ZkStateReader$3.process Updating live nodes... (2)
   [junit4]   2> 829318 T3293 oascc.ZkStateReader$3.process Updating live nodes... (2)
   [junit4]   2> 829321 T3295 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 829321 T3227 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
   [junit4]   2> 829321 T3295 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 829321 T3295 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 829323 T3296 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 829323 T3296 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> 829323 T3296 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
   [junit4]   2> 829325 T3295 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 829327 T3293 oascc.ZkStateReader$3.process Updating live nodes... (1)
   [junit4]   2> 829327 T3299 oascc.ZkStateReader$3.process Updating live nodes... (1)
   [junit4]   2> 829328 T3299 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 829329 T3295 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 829329 T3227 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
   [junit4]   2> 829330 T3296 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> 829330 T3296 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
   [junit4]   2> 829332 T3295 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 829335 T3295 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 829335 T3227 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 829337 T3301 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@13f514e name:ZooKeeperConnection Watcher:127.0.0.1:48045/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 829338 T3227 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 829339 T3227 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 829341 T3227 oascc.SolrZkClient.makePath makePath: /live_nodes/node2
   [junit4]   2> 829342 T3299 oascc.ZkStateReader$3.process Updating live nodes... (2)
   [junit4]   2> 829343 T3301 oascc.ZkStateReader$3.process Updating live nodes... (2)
   [junit4]   2> 829343 T3277 oasc.OverseerTest$OverseerRestarter.run Killing overseer.
   [junit4]   2> 829344 T3277 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 829344 T3227 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
   [junit4]   2> 829345 T3303 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@10f5d6c name:ZooKeeperConnection Watcher:127.0.0.1:48045/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 829345 T3277 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 829347 T3277 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:48045_solr
   [junit4]   2> 829348 T3277 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
   [junit4]   2> 829349 T3227 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 829349 T3277 oasc.Overseer.start Overseer (id=91349910558539788-127.0.0.1:48045_solr-n_0000000003) starting
   [junit4]   2> 829352 T3305 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
   [junit4]   2> 829353 T3305 oasc.OverseerCollectionProcessor.prioritizeOverseerNodes prioritizing overseer nodes
   [junit4]   2> 829354 T3304 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 829354 T3304 oasc.Overseer$ClusterStateUpdater.run Replaying operations from work queue.
   [junit4]   2> 829355 T3304 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> 829355 T3304 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
   [junit4]   2> 829355 T3301 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> 829355 T3299 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> 829358 T3304 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> 829358 T3304 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
   [junit4]   2> 829359 T3299 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> 829359 T3301 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> 829361 T3299 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> 829361 T3301 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> 829363 T3304 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
   [junit4]   2> 829364 T3304 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 829364 T3304 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> 829365 T3304 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
   [junit4]   2> 829367 T3303 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 829369 T3301 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> 829369 T3299 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> 829550 T3227 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 829553 T3303 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 829553 T3227 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
   [junit4]   2> 829555 T3304 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 829555 T3304 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> 829556 T3304 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
   [junit4]   2> 829558 T3303 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 829559 T3301 oascc.ZkStateReader$3.process Updating live nodes... (1)
   [junit4]   2> 829559 T3299 oascc.ZkStateReader$3.process Updating live nodes... (1)
   [junit4]   2> 829560 T3299 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> 829560 T3299 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> 829561 T3227 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 829561 T3301 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 829564 T3303 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 829566 T3303 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 829668 T3301 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> 829762 T3227 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 829764 T3227 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 829767 T3307 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@a244bf name:ZooKeeperConnection Watcher:127.0.0.1:48045/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 829767 T3

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

pache.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> 845553 T3525 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
   [junit4]   2> 845562 T3527 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
   [junit4]   2> 845580 T3531 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
   [junit4]   2> 845588 T3535 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
   [junit4]   2> 845594 T3537 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
   [junit4]   2> 845618 T3541 oasc.LeaderElector$1.process WARN  org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /collections/collection1/leader_elect/shard5/election/91349911456710733-node73_core73-n_0000000005
   [junit4]   2> 	at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
   [junit4]   2> 	at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
   [junit4]   2> 	at org.apache.zookeeper.ZooKeeper.getData(ZooKeeper.java: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.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> 845619 T3541 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
   [junit4]   2> 845653 T3549 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
   [junit4]   2> 845654 T3551 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
   [junit4]   2> 845665 T3555 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
   [junit4]   2> 845690 T3563 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
   [junit4]   2> 845693 T3565 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
   [junit4]   2> 845759 T3581 oasc.LeaderElector$1.process WARN  org.apache.solr.common.SolrException: Could not register as the leader because creating the ephemeral registration node in ZooKeeper failed
   [junit4]   2> 	at org.apache.solr.cloud.ShardLeaderElectionContextBase.runLeaderProcess(ElectionContext.java:135)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector.runIamLeaderProcess(LeaderElector.java:164)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:108)
   [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> Caused by: org.apache.solr.common.SolrException: org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /collections/collection1/leaders/shard8
   [junit4]   2> 	at org.apache.solr.common.util.RetryUtil.retryOnThrowable(RetryUtil.java:40)
   [junit4]   2> 	at org.apache.solr.cloud.ShardLeaderElectionContextBase.runLeaderProcess(ElectionContext.java:122)
   [junit4]   2> 	... 6 more
   [junit4]   2> Caused by: org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /collections/collection1/leaders/shard8
   [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.create(ZooKeeper.java:783)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient$10.execute(SolrZkClient.java:431)
   [junit4]   2> 	at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:428)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:385)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:372)
   [junit4]   2> 	at org.apache.solr.cloud.ShardLeaderElectionContextBase$1.execute(ElectionContext.java:127)
   [junit4]   2> 	at org.apache.solr.common.util.RetryUtil.retryOnThrowable(RetryUtil.java:34)
   [junit4]   2> 	... 7 more
   [junit4]   2> 
   [junit4]   2> 845761 T3581 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
   [junit4]   2> 845797 T3597 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
   [junit4]   2> 845801 T3601 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
   [junit4]   2> 848175 T3227 oas.SolrTestCaseJ4.deleteCore ###deleteCore
   [junit4]   2> NOTE: test params are: codec=Lucene41, sim=DefaultSimilarity, locale=de, timezone=Asia/Pyongyang
   [junit4]   2> NOTE: Linux 3.8.0-36-generic i386/Oracle Corporation 1.7.0_60-ea (32-bit)/cpus=8,threads=1,free=337867704,total=536870912
   [junit4]   2> NOTE: All tests run in this JVM: [CoreContainerCoreInitFailuresTest, TestIndexingPerformance, OverseerRolesTest, DebugComponentTest, HighlighterConfigTest, TestSearcherReuse, StandardRequestHandlerTest, TestQueryTypes, IndexSchemaRuntimeFieldTest, TestFieldResource, TestInitQParser, DocumentAnalysisRequestHandlerTest, TestDistributedSearch, UniqFieldsUpdateProcessorFactoryTest, StatsComponentTest, TestSolr4Spatial, TestStressRecovery, TestSolrXmlPersistence, CurrencyFieldOpenExchangeTest, PingRequestHandlerTest, XmlUpdateRequestHandlerTest, SuggesterTSTTest, RequiredFieldsTest, TestShardHandlerFactory, BasicDistributedZk2Test, TestSerializedLuceneMatchVersion, TestPhraseSuggestions, FullSolrCloudDistribCmdsTest, OutputWriterTest, TestPartialUpdateDeduplication, TestFieldTypeResource, DirectUpdateHandlerTest, TestOmitPositions, SimplePostToolTest, HardAutoCommitTest, TestAddFieldRealTimeGet, HdfsLockFactoryTest, NoCacheHeaderTest, CachingDirectoryFactoryTest, LeaderElectionIntegrationTest, CurrencyFieldXmlFileTest, TestBinaryField, TestDistribDocBasedVersion, CollectionsAPIDistributedZkTest, DocValuesMultiTest, TestRangeQuery, TestStressLucene, TestLazyCores, TestSchemaResource, MinimalSchemaTest, TestFastOutputStream, ChaosMonkeyNothingIsSafeTest, BlockDirectoryTest, BadCopyFieldTest, TestAtomicUpdateErrorCases, TestSchemaSimilarityResource, TestRTGBase, RequestHandlersTest, TestFreeTextSuggestions, PreAnalyzedFieldTest, TestClassNameShortening, TestCollationFieldDocValues, TestSchemaNameResource, HighlighterTest, TestArbitraryIndexDir, SolrCmdDistributorTest, AlternateDirectoryTest, TestFuzzyAnalyzedSuggestions, SortByFunctionTest, SpellCheckCollatorTest, ChaosMonkeySafeLeaderTest, TestUtils, TestMaxScoreQueryParser, DateFieldTest, TestFastWriter, TestQuerySenderListener, TestUpdate, ShardRoutingCustomTest, ConvertedLegacyTest, FieldAnalysisRequestHandlerTest, TestManagedSchemaFieldResource, HdfsDirectoryTest, ZkNodePropsTest, ChangedSchemaMergeTest, PrimUtilsTest, TestReloadAndDeleteDocs, TestDefaultSimilarityFactory, UnloadDistributedZkTest, SyncSliceTest, OverseerTest]
   [junit4] Completed on J1 in 40.60s, 8 tests, 1 error <<< FAILURES!

[...truncated 546 lines...]
BUILD FAILED
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/build.xml:471: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/build.xml:451: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/build.xml:39: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/extra-targets.xml:37: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build.xml:189: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/common-build.xml:490: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/lucene/common-build.xml:1278: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/lucene/common-build.xml:911: There were test failures: 366 suites, 1573 tests, 1 error, 36 ignored (8 assumptions)

Total time: 44 minutes 38 seconds
Build step 'Invoke Ant' marked build as failure
Description set: Java: 32bit/jdk1.7.0_60-ea-b04 -client -XX:+UseG1GC
Archiving artifacts
Recording test results
Email was triggered for: Failure
Sending email for trigger: Failure