lucene-dev mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From Policeman Jenkins Server <jenk...@thetaphi.de>
Subject [JENKINS] Lucene-Solr-trunk-Linux (64bit/jdk1.7.0_65) - Build # 10988 - Failure!
Date Sat, 09 Aug 2014 20:18:26 GMT
Build: http://jenkins.thetaphi.de/job/Lucene-Solr-trunk-Linux/10988/
Java: 64bit/jdk1.7.0_65 -XX:+UseCompressedOops -XX:+UseParallelGC

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([B47403706B1EEDE7:B07C8C8379BB02C6]:0)
	at org.apache.solr.cloud.ShardLeaderElectionContextBase.runLeaderProcess(ElectionContext.java:144)
	at org.apache.solr.cloud.LeaderElector.runIamLeaderProcess(LeaderElector.java:163)
	at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:125)
	at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:155)
	at org.apache.solr.cloud.LeaderElector.joinElection(LeaderElector.java:314)
	at org.apache.solr.cloud.LeaderElector.joinElection(LeaderElector.java:221)
	at org.apache.solr.cloud.OverseerTest$MockZKController.publishState(OverseerTest.java:155)
	at org.apache.solr.cloud.OverseerTest.testOverseerFailure(OverseerTest.java:660)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:606)
	at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1618)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:827)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:863)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:877)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
	at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:50)
	at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
	at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:49)
	at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:65)
	at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:365)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:798)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:458)
	at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:836)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:738)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:772)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:783)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
	at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
	at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:42)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
	at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
	at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:43)
	at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
	at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:65)
	at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:55)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:365)
	at java.lang.Thread.run(Thread.java:745)
Caused by: org.apache.zookeeper.KeeperException$NodeExistsException: KeeperErrorCode = NodeExists for /collections/collection1/leaders/shard1
	at org.apache.zookeeper.KeeperException.create(KeeperException.java:119)
	at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
	at org.apache.zookeeper.ZooKeeper.create(ZooKeeper.java:783)
	at org.apache.solr.common.cloud.SolrZkClient$11.execute(SolrZkClient.java:457)
	at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
	at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:454)
	at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:411)
	at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:398)
	at org.apache.solr.cloud.ShardLeaderElectionContextBase$1.execute(ElectionContext.java:136)
	at org.apache.solr.common.util.RetryUtil.retryOnThrowable(RetryUtil.java:31)
	at org.apache.solr.cloud.ShardLeaderElectionContextBase.runLeaderProcess(ElectionContext.java:131)
	... 47 more




Build Log:
[...truncated 11535 lines...]
   [junit4] Suite: org.apache.solr.cloud.OverseerTest
   [junit4]   2> Creating dataDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./temp/solr.cloud.OverseerTest-B47403706B1EEDE7-001/init-core-data-001
   [junit4]   2> 1852695 T5168 oas.SolrTestCaseJ4.buildSSLConfig Randomized ssl (true) and clientAuth (false)
   [junit4]   2> 1852695 T5168 oas.SolrTestCaseJ4.initCore ####initCore
   [junit4]   2> 1852695 T5168 oas.SolrTestCaseJ4.initCore ####initCore end
   [junit4]   2> 1852698 T5168 oas.SolrTestCaseJ4.setUp ###Starting testStateChange
   [junit4]   2> 1852699 T5168 oasc.ZkTestServer.run STARTING ZK TEST SERVER
   [junit4]   1> client port:0.0.0.0/0.0.0.0:0
   [junit4]   2> 1852700 T5169 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
   [junit4]   2> 1852800 T5168 oasc.ZkTestServer.run start zk server on port:45454
   [junit4]   2> 1852802 T5168 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1852804 T5175 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@55e0a3b2 name:ZooKeeperConnection Watcher:127.0.0.1:45454/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1852804 T5168 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1852806 T5168 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1852808 T5177 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@436ce76e name:ZooKeeperConnection Watcher:127.0.0.1:45454 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1852808 T5168 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1852812 T5168 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1852814 T5179 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1edcf90b name:ZooKeeperConnection Watcher:127.0.0.1:45454 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1852814 T5168 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1852814 T5168 oascc.SolrZkClient.makePath makePath: /solr
   [junit4]   2> 1852819 T5168 oascc.SolrZkClient.makePath makePath: /live_nodes
   [junit4]   2> 1852822 T5168 oascc.SolrZkClient.makePath makePath: /clusterstate.json
   [junit4]   2> 1852825 T5168 oascc.SolrZkClient.makePath makePath: /aliases.json
   [junit4]   2> 1852826 T5168 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 1852829 T5168 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1852830 T5181 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@478d9ad4 name:ZooKeeperConnection Watcher:127.0.0.1:45454/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1852830 T5168 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1852831 T5168 oascc.SolrZkClient.makePath makePath: /overseer_elect
   [junit4]   2> 1852833 T5168 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
   [junit4]   2> 1852835 T5168 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:45454_solr
   [junit4]   2> 1852835 T5168 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
   [junit4]   2> 1852836 T5168 oasc.Overseer.start Overseer (id=92249415034929155-127.0.0.1:45454_solr-n_0000000000) starting
   [junit4]   2> 1852837 T5168 oascc.SolrZkClient.makePath makePath: /overseer/queue
   [junit4]   2> 1852838 T5168 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
   [junit4]   2> 1852840 T5168 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-failure
   [junit4]   2> 1852843 T5168 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-running
   [junit4]   2> 1852845 T5168 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-completed
   [junit4]   2> 1852848 T5168 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
   [junit4]   2> 1852852 T5183 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
   [junit4]   2> 1852853 T5182 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
   [junit4]   2> 1852853 T5168 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1852854 T5182 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1852854 T5182 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=null message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "base_url":"http://127.0.0.1/solr",
   [junit4]   2> 	  "node_name":"node1",
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "core":"core1",
   [junit4]   2> 	  "roles":"",
   [junit4]   2> 	  "state":"recovering"}
   [junit4]   2> 1852854 T5182 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
   [junit4]   2> 1852856 T5184 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1852856 T5185 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 0)
   [junit4]   2> 1852904 T5168 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1852906 T5184 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1852907 T5182 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1852908 T5182 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=null message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "base_url":"http://127.0.0.1/solr",
   [junit4]   2> 	  "node_name":"node1",
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "core":"core1",
   [junit4]   2> 	  "roles":"",
   [junit4]   2> 	  "state":"active"}
   [junit4]   2> 1852908 T5182 oasc.Overseer$ClusterStateUpdater.updateState node=core_node1 is already registered
   [junit4]   2> 1852908 T5182 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
   [junit4]   2> 1853011 T5185 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 0)
   [junit4]   2> 1853061 T5168 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:45454 45454
   [junit4]   2> 1853776 T5169 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:45454 45454
   [junit4]   2> 1853777 T5168 oas.SolrTestCaseJ4.tearDown ###Ending testStateChange
   [junit4]   2> 1853777 T5182 oasc.Overseer$ClusterStateUpdater.run Overseer Loop exiting : 127.0.0.1:45454_solr
   [junit4]   2> 1853779 T5186 oasc.Overseer$ClusterStateUpdater.checkIfIamStillLeader ERROR could not read the data org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /overseer_elect/leader
   [junit4]   2> 	at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
   [junit4]   2> 	at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
   [junit4]   2> 	at org.apache.zookeeper.ZooKeeper.getData(ZooKeeper.java:1155)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient$8.execute(SolrZkClient.java:302)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient$8.execute(SolrZkClient.java:299)
   [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:299)
   [junit4]   2> 	at org.apache.solr.cloud.Overseer$ClusterStateUpdater.checkIfIamStillLeader(Overseer.java:317)
   [junit4]   2> 	at org.apache.solr.cloud.Overseer$ClusterStateUpdater.access$300(Overseer.java:85)
   [junit4]   2> 	at org.apache.solr.cloud.Overseer$ClusterStateUpdater$1.run(Overseer.java:289)
   [junit4]   2> 
   [junit4]   2> 1853784 T5168 oas.SolrTestCaseJ4.setUp ###Starting testDoubleAssignment
   [junit4]   2> 1853784 T5168 oasc.ZkTestServer.run STARTING ZK TEST SERVER
   [junit4]   1> client port:0.0.0.0/0.0.0.0:0
   [junit4]   2> 1853785 T5187 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
   [junit4]   2> 1853885 T5168 oasc.ZkTestServer.run start zk server on port:44593
   [junit4]   2> 1853886 T5168 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1853888 T5193 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@91a5982 name:ZooKeeperConnection Watcher:127.0.0.1:44593/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1853888 T5168 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1853889 T5168 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1853890 T5195 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@166c9c22 name:ZooKeeperConnection Watcher:127.0.0.1:44593 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1853890 T5168 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1853892 T5168 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1853893 T5197 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@59d9334a name:ZooKeeperConnection Watcher:127.0.0.1:44593 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1853893 T5168 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1853893 T5168 oascc.SolrZkClient.makePath makePath: /solr
   [junit4]   2> 1853895 T5168 oascc.SolrZkClient.makePath makePath: /live_nodes
   [junit4]   2> 1853897 T5168 oascc.SolrZkClient.makePath makePath: /clusterstate.json
   [junit4]   2> 1853898 T5168 oascc.SolrZkClient.makePath makePath: /aliases.json
   [junit4]   2> 1853899 T5168 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 1853901 T5168 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1853902 T5199 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@47c48b77 name:ZooKeeperConnection Watcher:127.0.0.1:44593/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1853902 T5168 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1853903 T5168 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 1853904 T5168 oascc.SolrZkClient.makePath makePath: /live_nodes/node1
   [junit4]   2> 1853906 T5168 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1853907 T5203 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@4cb8bf8d name:ZooKeeperConnection Watcher:127.0.0.1:44593/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1853908 T5168 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1853909 T5168 oascc.SolrZkClient.makePath makePath: /overseer_elect
   [junit4]   2> 1853910 T5168 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
   [junit4]   2> 1853912 T5168 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:44593_solr
   [junit4]   2> 1853912 T5168 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
   [junit4]   2> 1853913 T5168 oasc.Overseer.start Overseer (id=92249415106035716-127.0.0.1:44593_solr-n_0000000000) starting
   [junit4]   2> 1853914 T5168 oascc.SolrZkClient.makePath makePath: /overseer/queue
   [junit4]   2> 1853916 T5168 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
   [junit4]   2> 1853917 T5168 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-failure
   [junit4]   2> 1853919 T5168 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-running
   [junit4]   2> 1853921 T5168 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-completed
   [junit4]   2> 1853922 T5168 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
   [junit4]   2> 1853925 T5205 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
   [junit4]   2> 1853926 T5204 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
   [junit4]   2> 1853927 T5206 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1853928 T5204 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1853929 T5204 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> 1853929 T5204 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1]
   [junit4]   2> 1853929 T5204 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
   [junit4]   2> 1853931 T5200 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> 1853931 T5201 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> 1854428 T5168 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
   [junit4]   2> 1854432 T5168 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 1854435 T5206 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1854435 T5168 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1854438 T5204 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1854440 T5168 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1854441 T5208 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@48ac0e0a name:ZooKeeperConnection Watcher:127.0.0.1:44593/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1854441 T5168 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1854443 T5168 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 1854444 T5168 oascc.SolrZkClient.makePath makePath: /live_nodes/node1
   [junit4]   2> 1854447 T5168 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
   [junit4]   2> 1854447 T5206 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1854448 T5204 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> 1854448 T5204 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
   [junit4]   2> 1854450 T5168 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 1854453 T5206 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1854556 T5201 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> 1854556 T5209 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> 1854557 T5168 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1854561 T5168 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:44593 44593
   [junit4]   2> 1855145 T5187 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:44593 44593
   [junit4]   2> 1855147 T5168 oas.SolrTestCaseJ4.tearDown ###Ending testDoubleAssignment
   [junit4]   2> 1855150 T5204 oasc.Overseer$ClusterStateUpdater.run Overseer Loop exiting : 127.0.0.1:44593_solr
   [junit4]   2> 1855158 T5210 oasc.Overseer$ClusterStateUpdater.checkIfIamStillLeader ERROR could not read the data org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /overseer_elect/leader
   [junit4]   2> 	at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
   [junit4]   2> 	at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
   [junit4]   2> 	at org.apache.zookeeper.ZooKeeper.getData(ZooKeeper.java:1155)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient$8.execute(SolrZkClient.java:302)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient$8.execute(SolrZkClient.java:299)
   [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:299)
   [junit4]   2> 	at org.apache.solr.cloud.Overseer$ClusterStateUpdater.checkIfIamStillLeader(Overseer.java:317)
   [junit4]   2> 	at org.apache.solr.cloud.Overseer$ClusterStateUpdater.access$300(Overseer.java:85)
   [junit4]   2> 	at org.apache.solr.cloud.Overseer$ClusterStateUpdater$1.run(Overseer.java:289)
   [junit4]   2> 
   [junit4]   2> 1855164 T5168 oas.SolrTestCaseJ4.setUp ###Starting testReplay
   [junit4]   2> 1855164 T5168 oasc.ZkTestServer.run STARTING ZK TEST SERVER
   [junit4]   1> client port:0.0.0.0/0.0.0.0:0
   [junit4]   2> 1855167 T5211 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
   [junit4]   2> 1855268 T5168 oasc.ZkTestServer.run start zk server on port:57440
   [junit4]   2> 1855271 T5168 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1855274 T5217 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@526746f8 name:ZooKeeperConnection Watcher:127.0.0.1:57440/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1855274 T5168 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1855281 T5168 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1855282 T5219 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@bd9ebd4 name:ZooKeeperConnection Watcher:127.0.0.1:57440 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1855282 T5168 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1855326 T5168 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1855326 T5221 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@231f079f name:ZooKeeperConnection Watcher:127.0.0.1:57440 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1855328 T5168 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1855328 T5168 oascc.SolrZkClient.makePath makePath: /solr
   [junit4]   2> 1855331 T5168 oascc.SolrZkClient.makePath makePath: /live_nodes
   [junit4]   2> 1855334 T5168 oascc.SolrZkClient.makePath makePath: /clusterstate.json
   [junit4]   2> 1855335 T5168 oascc.SolrZkClient.makePath makePath: /aliases.json
   [junit4]   2> 1855337 T5168 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 1855339 T5168 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
   [junit4]   2> 1855343 T5168 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1855344 T5223 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@148e01cc name:ZooKeeperConnection Watcher:127.0.0.1:57440/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1855344 T5168 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1855346 T5168 oascc.SolrZkClient.makePath makePath: /overseer_elect
   [junit4]   2> 1855347 T5168 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
   [junit4]   2> 1855357 T5168 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:57440_solr
   [junit4]   2> 1855357 T5168 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
   [junit4]   2> 1855359 T5168 oasc.Overseer.start Overseer (id=92249415196803075-127.0.0.1:57440_solr-n_0000000000) starting
   [junit4]   2> 1855360 T5168 oascc.SolrZkClient.makePath makePath: /overseer/queue
   [junit4]   2> 1855363 T5168 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-failure
   [junit4]   2> 1855366 T5168 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-running
   [junit4]   2> 1855370 T5168 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-completed
   [junit4]   2> 1855387 T5168 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
   [junit4]   2> 1855422 T5225 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
   [junit4]   2> 1855428 T5224 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1855428 T5224 oasc.Overseer$ClusterStateUpdater.run Replaying operations from work queue.
   [junit4]   2> 1855429 T5224 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=null message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "base_url":"http://127.0.0.1/solr",
   [junit4]   2> 	  "node_name":"node1",
   [junit4]   2> 	  "shard":"s1",
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "core":"core1",
   [junit4]   2> 	  "roles":"",
   [junit4]   2> 	  "state":"recovering"}
   [junit4]   2> 1855432 T5224 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=null message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "base_url":"http://127.0.0.1/solr",
   [junit4]   2> 	  "node_name":"node1",
   [junit4]   2> 	  "shard":"s1",
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "core":"core2",
   [junit4]   2> 	  "roles":"",
   [junit4]   2> 	  "state":"recovering"}
   [junit4]   2> 1855447 T5226 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 0)
   [junit4]   2> 1855447 T5224 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
   [junit4]   2> 1855450 T5224 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1855450 T5224 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=null message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "base_url":"http://127.0.0.1/solr",
   [junit4]   2> 	  "node_name":"node1",
   [junit4]   2> 	  "shard":"s1",
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "core":"core3",
   [junit4]   2> 	  "roles":"",
   [junit4]   2> 	  "state":"recovering"}
   [junit4]   2> 1855452 T5227 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1855452 T5226 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 0)
   [junit4]   2> 1855527 T5168 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:57440 57440
   [junit4]   2> 1855964 T5211 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:57440 57440
   [junit4]   2> 1855965 T5168 oas.SolrTestCaseJ4.tearDown ###Ending testReplay
   [junit4]   2> 1855965 T5224 oasc.Overseer$ClusterStateUpdater.run Overseer Loop exiting : 127.0.0.1:57440_solr
   [junit4]   2> 1855973 T5228 oasc.Overseer$ClusterStateUpdater.checkIfIamStillLeader ERROR could not read the data org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /overseer_elect/leader
   [junit4]   2> 	at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
   [junit4]   2> 	at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
   [junit4]   2> 	at org.apache.zookeeper.ZooKeeper.getData(ZooKeeper.java:1155)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient$8.execute(SolrZkClient.java:302)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient$8.execute(SolrZkClient.java:299)
   [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:299)
   [junit4]   2> 	at org.apache.solr.cloud.Overseer$ClusterStateUpdater.checkIfIamStillLeader(Overseer.java:317)
   [junit4]   2> 	at org.apache.solr.cloud.Overseer$ClusterStateUpdater.access$300(Overseer.java:85)
   [junit4]   2> 	at org.apache.solr.cloud.Overseer$ClusterStateUpdater$1.run(Overseer.java:289)
   [junit4]   2> 
   [junit4]   2> 1855979 T5168 oas.SolrTestCaseJ4.setUp ###Starting testBadQueueItem
   [junit4]   2> 1855980 T5168 oasc.ZkTestServer.run STARTING ZK TEST SERVER
   [junit4]   1> client port:0.0.0.0/0.0.0.0:0
   [junit4]   2> 1855980 T5229 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
   [junit4]   2> 1856080 T5168 oasc.ZkTestServer.run start zk server on port:56054
   [junit4]   2> 1856081 T5168 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1856084 T5235 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@6ec88c20 name:ZooKeeperConnection Watcher:127.0.0.1:56054 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1856085 T5168 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1856087 T5168 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1856088 T5237 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@7f10ade3 name:ZooKeeperConnection Watcher:127.0.0.1:56054 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1856088 T5168 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1856089 T5168 oascc.SolrZkClient.makePath makePath: /solr
   [junit4]   2> 1856092 T5168 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1856094 T5239 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1b3ede15 name:ZooKeeperConnection Watcher:127.0.0.1:56054/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1856095 T5168 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1856095 T5168 oascc.SolrZkClient.makePath makePath: /live_nodes
   [junit4]   2> 1856097 T5168 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1856099 T5241 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@5b492853 name:ZooKeeperConnection Watcher:127.0.0.1:56054/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1856099 T5168 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1856100 T5168 oascc.SolrZkClient.makePath makePath: /overseer_elect
   [junit4]   2> 1856102 T5168 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
   [junit4]   2> 1856104 T5168 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:56054_solr
   [junit4]   2> 1856104 T5168 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
   [junit4]   2> 1856105 T5168 oasc.Overseer.start Overseer (id=92249415249952771-127.0.0.1:56054_solr-n_0000000000) starting
   [junit4]   2> 1856106 T5168 oascc.SolrZkClient.makePath makePath: /overseer/queue
   [junit4]   2> 1856108 T5168 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
   [junit4]   2> 1856110 T5168 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-failure
   [junit4]   2> 1856111 T5168 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-running
   [junit4]   2> 1856113 T5168 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-completed
   [junit4]   2> 1856115 T5168 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
   [junit4]   2> 1856118 T5243 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
   [junit4]   2> 1856118 T5168 oascc.SolrZkClient.makePath makePath: /clusterstate.json
   [junit4]   2> 1856118 T5242 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
   [junit4]   2> 1856120 T5168 oascc.SolrZkClient.makePath makePath: /aliases.json
   [junit4]   2> 1856121 T5168 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 1856122 T5168 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1856124 T5245 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@3cc5a9b7 name:ZooKeeperConnection Watcher:127.0.0.1:56054/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1856124 T5168 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1856126 T5168 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 1856127 T5168 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1
   [junit4]   2> 1856131 T5248 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1856132 T5242 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1856133 T5242 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"active",
   [junit4]   2> 	  "node_name":"127.0.0.1",
   [junit4]   2> 	  "core":"core1",
   [junit4]   2> 	  "core_node_name":"node1",
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "numShards":"3",
   [junit4]   2> 	  "base_url":"http://127.0.0.1/solr/"}
   [junit4]   2> 1856133 T5242 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1, shard2, shard3]
   [junit4]   2> 1856133 T5242 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard2
   [junit4]   2> 1856135 T5247 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> 1856135 T5246 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> 1856631 T5168 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard2/election
   [junit4]   2> 1856636 T5168 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard2
   [junit4]   2> 1856639 T5248 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1856640 T5242 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1856642 T5242 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"active",
   [junit4]   2> 	  "node_name":"127.0.0.1",
   [junit4]   2> 	  "core":"core2",
   [junit4]   2> 	  "core_node_name":"node2",
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "numShards":"3",
   [junit4]   2> 	  "base_url":"http://127.0.0.1/solr/"}
   [junit4]   2> 1856642 T5242 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
   [junit4]   2> 1856642 T5242 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard3
   [junit4]   2> 1856643 T5248 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1856745 T5247 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> 1856745 T5246 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> 1857140 T5168 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard3/election
   [junit4]   2> 1857144 T5168 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard3
   [junit4]   2> 1857147 T5248 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1857148 T5242 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1857150 T5242 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"active",
   [junit4]   2> 	  "node_name":"127.0.0.1",
   [junit4]   2> 	  "core":"core3",
   [junit4]   2> 	  "core_node_name":"node3",
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "numShards":"3",
   [junit4]   2> 	  "base_url":"http://127.0.0.1/solr/"}
   [junit4]   2> 1857151 T5242 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
   [junit4]   2> 1857151 T5242 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
   [junit4]   2> 1857152 T5248 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1857152 T5247 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> 1857152 T5246 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> 1857649 T5168 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
   [junit4]   2> 1857653 T5168 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 1857656 T5248 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1857657 T5242 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1857759 T5247 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> 1857759 T5246 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> 1857807 T5248 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1857809 T5242 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1857809 T5242 oasc.Overseer$ClusterStateUpdater.checkKeyExistence ERROR Skipping invalid Overseer message because it has no collection specified: {
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"active",
   [junit4]   2> 	  "node_name":"127.0.0.1",
   [junit4]   2> 	  "core":"core0",
   [junit4]   2> 	  "core_node_name":"node0",
   [junit4]   2> 	  "collection":"",
   [junit4]   2> 	  "numShards":"1",
   [junit4]   2> 	  "base_url":"http://127.0.0.1/solr/"}
   [junit4]   2> 1857812 T5242 oasc.Overseer$ClusterStateUpdater.checkKeyExistence ERROR Skipping invalid Overseer message because it has no collection specified: {
   [junit4]   2> 	  "operation":"deletecore",
   [junit4]   2> 	  "node_name":"127.0.0.1",
   [junit4]   2> 	  "core":"core0",
   [junit4]   2> 	  "core_node_name":"node0",
   [junit4]   2> 	  "collection":""}
   [junit4]   2> 1857814 T5248 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1857814 T5242 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"active",
   [junit4]   2> 	  "node_name":"127.0.0.1",
   [junit4]   2> 	  "core":"core1",
   [junit4]   2> 	  "core_node_name":"node1",
   [junit4]   2> 	  "collection":"collection2",
   [junit4]   2> 	  "numShards":"3",
   [junit4]   2> 	  "base_url":"http://127.0.0.1/solr/"}
   [junit4]   2> 1857814 T5242 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection2 with shards [shard1, shard2, shard3]
   [junit4]   2> 1857815 T5242 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard2
   [junit4]   2> 1857917 T5246 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> 1857917 T5247 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> 1858310 T5168 oascc.SolrZkClient.makePath makePath: /collections/collection2/leader_elect/shard2/election
   [junit4]   2> 1858315 T5168 oascc.SolrZkClient.makePath makePath: /collections/collection2/leaders/shard2
   [junit4]   2> 1858317 T5248 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1858318 T5242 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1858320 T5242 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"active",
   [junit4]   2> 	  "node_name":"127.0.0.1",
   [junit4]   2> 	  "core":"core2",
   [junit4]   2> 	  "core_node_name":"node2",
   [junit4]   2> 	  "collection":"collection2",
   [junit4]   2> 	  "numShards":"3",
   [junit4]   2> 	  "base_url":"http://127.0.0.1/solr/"}
   [junit4]   2> 1858320 T5242 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
   [junit4]   2> 1858320 T5242 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard3
   [junit4]   2> 1858321 T5248 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1858322 T5247 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> 1858322 T5246 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> 1858818 T5168 oascc.SolrZkClient.makePath makePath: /collections/collection2/leader_elect/shard3/election
   [junit4]   2> 1858825 T5168 oascc.SolrZkClient.makePath makePath: /collections/collection2/leaders/shard3
   [junit4]   2> 1858828 T5248 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1858831 T5242 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1858833 T5242 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"active",
   [junit4]   2> 	  "node_name":"127.0.0.1",
   [junit4]   2> 	  "core":"core3",
   [junit4]   2> 	  "core_node_name":"node3",
   [junit4]   2> 	  "collection":"collection2",
   [junit4]   2> 	  "numShards":"3",
   [junit4]   2> 	  "base_url":"http://127.0.0.1/solr/"}
   [junit4]   2> 1858833 T5242 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
   [junit4]   2> 1858833 T5242 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
   [junit4]   2> 1858835 T5248 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1858836 T5246 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> 1858837 T5247 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> 1859331 T5168 oascc.SolrZkClient.makePath makePath: /collections/collection2/leader_elect/shard1/election
   [junit4]   2> 1859335 T5168 oascc.SolrZkClient.makePath makePath: /collections/collection2/leaders/shard1
   [junit4]   2> 1859338 T5248 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1859339 T5242 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1859441 T5246 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> 1859442 T5247 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> 1859493 T5168 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:56054 56054
   [junit4]   2> 1860062 T5229 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:56054 56054
   [junit4]   2> 1860063 T5168 oas.SolrTestCaseJ4.tearDown ###Ending testBadQueueItem
   [junit4]   2> 1860063 T5242 oasc.Overseer$ClusterStateUpdater.run Overseer Loop exiting : 127.0.0.1:56054_solr
   [junit4]   2> 1860064 T5249 oasc.Overseer$ClusterStateUpdater.checkIfIamStillLeader ERROR could not read the data org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /overseer_elect/leader
   [junit4]   2> 	at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
   [junit4]   2> 	at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
   [junit4]   2> 	at org.apache.zookeeper.ZooKeeper.getData(ZooKeeper.java:1155)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient$8.execute(SolrZkClient.java:302)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient$8.execute(SolrZkClient.java:299)
   [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:299)
   [junit4]   2> 	at org.apache.solr.cloud.Overseer$ClusterStateUpdater.checkIfIamStillLeader(Overseer.java:317)
   [junit4]   2> 	at org.apache.solr.cloud.Overseer$ClusterStateUpdater.access$300(Overseer.java:85)
   [junit4]   2> 	at org.apache.solr.cloud.Overseer$ClusterStateUpdater$1.run(Overseer.java:289)
   [junit4]   2> 
   [junit4]   2> 1860069 T5168 oas.SolrTestCaseJ4.setUp ###Starting testOverseerFailure
   [junit4]   2> 1860070 T5168 oasc.ZkTestServer.run STARTING ZK TEST SERVER
   [junit4]   1> client port:0.0.0.0/0.0.0.0:0
   [junit4]   2> 1860071 T5250 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
   [junit4]   2> 1860171 T5168 oasc.ZkTestServer.run start zk server on port:53631
   [junit4]   2> 1860172 T5168 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1860174 T5256 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@5e07df67 name:ZooKeeperConnection Watcher:127.0.0.1:53631 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1860175 T5168 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1860177 T5168 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1860178 T5258 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@530a6cf7 name:ZooKeeperConnection Watcher:127.0.0.1:53631 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1860178 T5168 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1860179 T5168 oascc.SolrZkClient.makePath makePath: /solr
   [junit4]   2> 1860182 T5168 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1860183 T5260 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@4618f8ec name:ZooKeeperConnection Watcher:127.0.0.1:53631/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1860183 T5168 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1860183 T5168 oascc.SolrZkClient.makePath makePath: /live_nodes
   [junit4]   2> 1860185 T5168 oascc.SolrZkClient.makePath makePath: /clusterstate.json
   [junit4]   2> 1860186 T5168 oascc.SolrZkClient.makePath makePath: /aliases.json
   [junit4]   2> 1860188 T5168 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 1860190 T5168 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1860192 T5262 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@77245f80 name:ZooKeeperConnection Watcher:127.0.0.1:53631/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1860192 T5168 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1860193 T5168 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 1860195 T5168 oascc.SolrZkClient.makePath makePath: /live_nodes/node1
   [junit4]   2> 1860198 T5168 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1860199 T5266 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@14370a32 name:ZooKeeperConnection Watcher:127.0.0.1:53631/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1860200 T5168 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1860201 T5168 oascc.SolrZkClient.makePath makePath: /overseer_elect
   [junit4]   2> 1860203 T5168 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
   [junit4]   2> 1860205 T5168 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:53631_solr
   [junit4]   2> 1860206 T5168 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
   [junit4]   2> 1860207 T5168 oasc.Overseer.start Overseer (id=92249415517995012-127.0.0.1:53631_solr-n_0000000000) starting
   [junit4]   2> 1860208 T5168 oascc.SolrZkClient.makePath makePath: /overseer/queue
   [junit4]   2> 1860210 T5168 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
   [junit4]   2> 1860212 T5168 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-failure
   [junit4]   2> 1860213 T5168 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-running
   [junit4]   2> 1860215 T5168 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-completed
   [junit4]   2> 1860217 T5168 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
   [junit4]   2> 1860220 T5268 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
   [junit4]   2> 1860221 T5267 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
   [junit4]   2> 1861223 T5269 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1861224 T5267 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1861224 T5267 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> 1861224 T5267 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1]
   [junit4]   2> 1861224 T5267 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
   [junit4]   2> 1861226 T5263 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> 1861226 T5264 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> 1861723 T5168 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
   [junit4]   2> 1861728 T5168 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 1861731 T5269 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1861731 T5168 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1861732 T5267 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1861732 T5168 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
   [junit4]   2> 1861733 T5267 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> 1861734 T5267 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
   [junit4]   2> 1861735 T5269 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1861735 T5263 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> 1861735 T5264 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> 1862222 T5268 oasc.OverseerCollectionProcessor.amILeader  org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /overseer_elect/leader
   [junit4]   2> 	at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
   [junit4]   2> 	at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
   [junit4]   2> 	at org.apache.zookeeper.ZooKeeper.getData(ZooKeeper.java:1155)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient$8.execute(SolrZkClient.java:302)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient$8.execute(SolrZkClient.java:299)
   [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:299)
   [junit4]   2> 	at org.apache.solr.cloud.OverseerCollectionProcessor.amILeader(OverseerCollectionProcessor.java:514)
   [junit4]   2> 	at org.apache.solr.cloud.OverseerCollectionProcessor.run(OverseerCollectionProcessor.java:269)
   [junit4]   2> 	at java.lang.Thread.run(Thread.java:745)
   [junit4]   2> 
   [junit4]   2> 1862222 T5268 oasc.OverseerCollectionProcessor.amILeader According to ZK I (id=92249415517995012-127.0.0.1:53631_solr-n_0000000000) am no longer a leader.
   [junit4]   2> 1862788 T5168 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
   [junit4]   2> 1862792 T5168 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1862793 T5271 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@42ba3ed name:ZooKeeperConnection Watcher:127.0.0.1:53631/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1862793 T5168 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1862793 T5267 oasc.Overseer$ClusterStateUpdater.run Overseer Loop exiting : 127.0.0.1:53631_solr
   [junit4]   2> 1862795 T5272 oasc.Overseer$ClusterStateUpdater.checkIfIamStillLeader ERROR could not read the data org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /overseer_elect/leader
   [junit4]   2> 	at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
   [junit4]   2> 	at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
   [junit4]   2> 	at org.apache.zookeeper.ZooKeeper.getData(ZooKeeper.java:1155)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient$8.execute(SolrZkClient.java:302)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient$8.execute(SolrZkClient.java:299)
   [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:299)
   [junit4]   2> 	at org.apache.solr.cloud.Overseer$ClusterStateUpdater.checkIfIamStillLeader(Overseer.java:317)
   [junit4]   2> 	at org.apache.solr.cloud.Overseer$ClusterStateUpdater.access$300(Overseer.java:85)
   [junit4]   2> 	at org.apache.solr.cloud.Overseer$ClusterStateUpdater$1.run(Overseer.java:289)
   [junit4]   2> 
   [junit4]   2> 1862796 T5168 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:53631_solr
   [junit4]   2> 1862796 T5168 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
   [junit4]   2> 1862797 T5168 oasc.Overseer.start Overseer (id=92249415517995013-127.0.0.1:53631_solr-n_0000000001) starting
   [junit4]   2> 1862802 T5274 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
   [junit4]   2> 1862803 T5273 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
   [junit4]   2> 1862804 T5273 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1862804 T5273 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> 1862804 T5273 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
   [junit4]   2> 1862806 T5275 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1862806 T5264 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> 1862806 T5263 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> 1862858 T5275 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1862858 T5168 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
   [junit4]   2> 1862859 T5273 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1862861 T5168 oasc.LeaderElector.checkIfIamLeader WARN Failed setting watch org.apache.zookeeper.KeeperException$NoNodeException: KeeperErrorCode = NoNode for /collections/collection1/leader_elect/shard1/election/92249415517995011-node1_core1-n_0000000002
   [junit4]   2> 	at org.apache.zookeeper.KeeperException.create(KeeperException.java:111)
   [junit4]   2> 	at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
   [junit4]   2> 	at org.apache.zookeeper.ZooKeeper.getData(ZooKeeper.java:1155)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient$8.execute(SolrZkClient.java:302)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient$8.execute(SolrZkClient.java:299)
   [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:299)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:148)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector.joinElection(LeaderElector.java:314)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector.joinElection(LeaderElector.java:221)
   [junit4]   2> 	at org.apache.solr.cloud.OverseerTest$MockZKController.publishState(OverseerTest.java:155)
   [junit4]   2> 	at org.apache.solr.cloud.OverseerTest.testOverseerFailure(OverseerTest.java:660)
   [junit4]   2> 	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
   [junit4]   2> 	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
   [junit4]   2> 	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
   [junit4]   2> 	at java.lang.reflect.Method.invoke(Method.java:606)
   [junit4]   2> 	at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1618)
   [junit4]   2> 	at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:827)
   [junit4]   2> 	at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:863)
   [junit4]   2> 	at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:877)
   [junit4]   2> 	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
   [junit4]   2> 	at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:50)
   [junit4]   2> 	at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
   [junit4]   2> 	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
   [junit4]   2> 	at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:49)
   [junit4]   2> 	at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:65)
   [junit4]   2> 	at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
   [junit4]   2> 	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
   [junit4]   2> 	at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:365)
   [junit4]   2> 	at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:798)
   [junit4]   2> 	at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:458)
   [junit4]   2> 	at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:836)
   [junit4]   2> 	at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:738)
   [junit4]   2> 	at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:772)
   [junit4]   2> 	at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:783)
   [junit4]   2> 	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
   [junit4]   2> 	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
   [junit4]   2> 	at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
   [junit4]   2> 	at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:42)
   [junit4]   2> 	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
   [junit4]   2> 	at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
   [junit4]   2> 	at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
   [junit4]   2> 	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
   [junit4]   2> 	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
   [junit4]   2> 	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
   [junit4]   2> 	at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java: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:65)
   [junit4]   2> 	at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:55)
   [junit4]   2> 	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
   [junit4]   2> 	at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:365)
   [junit4]   2> 	at java.lang.Thread.run(Thread.java:745)
   [junit4]   2> 
   [junit4]   2> 1862863 T5273 oasc.SolrException.log ERROR Problem cleaning up collection in zk:collection1:org.apache.zookeeper.KeeperException$NotEmptyException: KeeperErrorCode = Directory not empty for /collections/collection1/leader_elect/shard1/election
   [junit4]   2> 		at org.apache.zookeeper.KeeperException.create(KeeperException.java:125)
   [junit4]   2> 		at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
   [junit4]   2> 		at org.apache.zookeeper.ZooKeeper.delete(ZooKeeper.java:873)
   [junit4]   2> 		at org.apache.solr.common.cloud.SolrZkClient$2.execute(SolrZkClient.java:184)
   [junit4]   2> 		at org.apache.solr.common.cloud.SolrZkClient$2.execute(SolrZkClient.java:181)
   [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:181)
   [junit4]   2> 		at org.apache.solr.common.cloud.SolrZkClient.clean(SolrZkClient.java:665)
   [junit4]   2> 		at org.apache.solr.common.cloud.SolrZkClient.clean(SolrZkClient.java:660)
   [junit4]   2> 		at org.apache.solr.common.cloud.SolrZkClient.clean(SolrZkClient.java:660)
   [junit4]   2> 		at org.apache.solr.common.cloud.SolrZkClient.clean(SolrZkClient.java:660)
   [junit4]   2> 		at org.apache.solr.cloud.Overseer$ClusterStateUpdater.removeCore(Overseer.java:1094)
   [junit4]   2> 		at org.apache.solr.cloud.Overseer$ClusterStateUpdater.processMessage(Overseer.java:359)
   [junit4]   2> 		at org.apache.solr.cloud.Overseer$ClusterStateUpdater.run(Overseer.java:242)
   [junit4]   2> 		at java.lang.Thread.run(Thread.java:745)
   [junit4]   2> 	
   [junit4]   2> 1862863 T5264 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 1862863 T5276 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 1862863 T5168 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 1862866 T5275 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1862867 T5273 oasc.Overseer$ClusterStateUpdater.setShardLeader ERROR Could not mark shard leader for non existing collection:collection1
   [junit4]   2> 1862969 T5263 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> 1862969 T5264 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> 1863866 T5276 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 1863866 T5168 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 1864869 T5276 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 1864869 T5168 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 1865871 T5276 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 1865871 T5168 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 1866873 T5276 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 1866874 T5168 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 1867876 T5276 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 1867876 T5168 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 1868880 T5276 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 1868880 T5168 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 1869884 T5276 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 1869884 T5168 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 1870888 T5276 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 1870888 T5168 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 1871890 T5276 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 1871890 T5168 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 1872892 T5276 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 1872893 T5168 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 1873896 T5276 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 1873896 T5168 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 1874899 T5276 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 1874899 T5168 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 1875902 T5276 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 1875902 T5168 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 1876904 T5276 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 1876905 T5168 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 1877906 T5276 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 1877907 T5168 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 1877909 T5276 oasc.LeaderElector$ElectionWatcher.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:144)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector.runIamLeaderProcess(LeaderElector.java:163)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:125)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector.access$200(LeaderElector.java:55)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector$ElectionWatcher.process(LeaderElector.java:358)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient$3$1.run(SolrZkClient.java:204)
   [junit4]   2> 	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
   [junit4]   2> 	at java.util.concurrent.FutureTask.run(FutureTask.java:262)
   [junit4]   2> 	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
   [junit4]   2> 	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
   [junit4]   2> 	at java.lang.Thread.run(Thread.java:745)
   [junit4]   2> Caused by: org.apache.zookeeper.KeeperException$NodeExistsException: KeeperErrorCode = NodeExists for /collections/collection1/leaders/shard1
   [junit4]   2> 	at org.apache.zookeeper.KeeperException.create(KeeperException.java:119)
   [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$11.execute(SolrZkClient.java:457)
   [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:454)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:411)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:398)
   [junit4]   2> 	at org.apache.solr.cloud.ShardLeaderElectionContextBase$1.execute(ElectionContext.java:136)
   [junit4]   2> 	at org.apache.solr.common.util.RetryUtil.retryOnThrowable(RetryUtil.java:31)
   [junit4]   2> 	at org.apache.solr.cloud.ShardLeaderElectionContextBase.runLeaderProcess(ElectionContext.java:131)
   [junit4]   2> 	... 10 more
   [junit4]   2> 
   [junit4]   2> 1877915 T5168 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:53631 53631
   [junit4]   2> 1878480 T5250 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:53631 53631
   [junit4]   2> 1878481 T5168 oas.SolrTestCaseJ4.tearDown ###Ending testOverseerFailure
   [junit4]   2> 1878482 T5273 oasc.Overseer$ClusterStateUpdater.run Overseer Loop exiting : 127.0.0.1:53631_solr
   [junit4]   2> 1878484 T5277 oasc.Overseer$ClusterStateUpdater.checkIfIamStillLeader ERROR could not read the data org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /overseer_elect/leader
   [junit4]   2> 	at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
   [junit4]   2> 	at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
   [junit4]   2> 	at org.apache.zookeeper.ZooKeeper.getData(ZooKeeper.java:1155)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient$8.execute(SolrZkClient.java:302)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient$8.execute(SolrZkClient.java:299)
   [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:299)
   [junit4]   2> 	at org.apache.solr.cloud.Overseer$ClusterStateUpdater.checkIfIamStillLeader(Overseer.java:317)
   [junit4]   2> 	at org.apache.solr.cloud.Overseer$ClusterStateUpdater.access$300(Overseer.java:85)
   [junit4]   2> 	at org.apache.solr.cloud.Overseer$ClusterStateUpdater$1.run(Overseer.java:289)
   [junit4]   2> 
   [junit4]   2> NOTE: reproduce with: ant test  -Dtestcase=OverseerTest -Dtests.method=testOverseerFailure -Dtests.seed=B47403706B1EEDE7 -Dtests.multiplier=3 -Dtests.slow=true -Dtests.locale=ms_MY -Dtests.timezone=Africa/Juba -Dtests.file.encoding=UTF-8
   [junit4] ERROR   18.4s J0 | 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([B47403706B1EEDE7:B07C8C8379BB02C6]:0)
   [junit4]    > 	at org.apache.solr.cloud.ShardLeaderElectionContextBase.runLeaderProcess(ElectionContext.java:144)
   [junit4]    > 	at org.apache.solr.cloud.LeaderElector.runIamLeaderProcess(LeaderElector.java:163)
   [junit4]    > 	at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:125)
   [junit4]    > 	at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:155)
   [junit4]    > 	at org.apache.solr.cloud.LeaderElector.joinElection(LeaderElector.java:314)
   [junit4]    > 	at org.apache.solr.cloud.LeaderElector.joinElection(LeaderElector.java:221)
   [junit4]    > 	at org.apache.solr.cloud.OverseerTest$MockZKController.publishState(OverseerTest.java:155)
   [junit4]    > 	at org.apache.solr.cloud.OverseerTest.testOverseerFailure(OverseerTest.java:660)
   [junit4]    > 	at java.lang.Thread.run(Thread.java:745)
   [junit4]    > Caused by: org.apache.zookeeper.KeeperException$NodeExistsException: KeeperErrorCode = NodeExists for /collections/collection1/leaders/shard1
   [junit4]    > 	at org.apache.zookeeper.KeeperException.create(KeeperException.java:119)
   [junit4]    > 	at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
   [junit4]    > 	at org.apache.zookeeper.ZooKeeper.create(ZooKeeper.java:783)
   [junit4]    > 	at org.apache.solr.common.cloud.SolrZkClient$11.execute(SolrZkClient.java:457)
   [junit4]    > 	at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
   [junit4]    > 	at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:454)
   [junit4]    > 	at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:411)
   [junit4]    > 	at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:398)
   [junit4]    > 	at org.apache.solr.cloud.ShardLeaderElectionContextBase$1.execute(ElectionContext.java:136)
   [junit4]    > 	at org.apache.solr.common.util.RetryUtil.retryOnThrowable(RetryUtil.java:31)
   [junit4]    > 	at org.apache.solr.cloud.ShardLeaderElectionContextBase.runLeaderProcess(ElectionContext.java:131)
   [junit4]    > 	... 47 more
   [junit4]   2> 1878509 T5168 oas.SolrTestCaseJ4.setUp ###Starting testShardAssignmentBigger
   [junit4]   2> 1878510 T5168 oasc.ZkTestServer.run STARTING ZK TEST SERVER
   [junit4]   1> client port:0.0.0.0/0.0.0.0:0
   [junit4]   2> 1878511 T5278 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
   [junit4]   2> 1878610 T5168 oasc.ZkTestServer.run start zk server on port:44196
   [junit4]   2> 1878611 T5168 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1878614 T5284 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@7d152f4e name:ZooKeeperConnection Watcher:127.0.0.1:44196 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1878614 T5168 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1878617 T5168 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1878618 T5286 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@3d668715 name:ZooKeeperConnection Watcher:127.0.0.1:44196 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1878618 T5168 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1878618 T5168 oascc.SolrZkClient.makePath makePath: /solr
   [junit4]   2> 1878627 T5168 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1878628 T5288 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@59cc1540 name:ZooKeeperConnection Watcher:127.0.0.1:44196/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1878628 T5168 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1878629 T5168 oascc.SolrZkClient.makePath makePath: /live_nodes
   [junit4]   2> 1878631 T5168 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1878632 T5290 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@63a63081 name:ZooKeeperConnection Watcher:127.0.0.1:44196/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1878632 T5168 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1878633 T5168 oascc.SolrZkClient.makePath makePath: /overseer_elect
   [junit4]   2> 1878634 T5168 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
   [junit4]   2> 1878636 T5168 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:44196_solr
   [junit4]   2> 1878636 T5168 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
   [junit4]   2> 1878638 T5168 oasc.Overseer.start Overseer (id=92249416726478851-127.0.0.1:44196_solr-n_0000000000) starting
   [junit4]   2> 1878639 T5168 oascc.SolrZkClient.makePath makePath: /overseer/queue
   [junit4]   2> 1878640 T5168 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
   [junit4]   2> 1878642 T5168 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-failure
   [junit4]   2> 1878644 T5168 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-running
   [junit4]   2> 1878646 T5168 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-completed
   [junit4]   2> 1878648 T5168 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
   [junit4]   2> 1878651 T5292 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
   [junit4]   2> 1878651 T5291 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
   [junit4]   2> 1878651 T5168 oascc.SolrZkClient.makePath makePath: /clusterstate.json
   [junit4]   2> 1878653 T5168 oascc.SolrZkClient.makePath makePath: /aliases.json
   [junit4]   2> 1878653 T5168 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 1878655 T5168 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1878656 T5294 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.Connection

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

Manager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1cd801b5 name:ZooKeeperConnection Watcher:127.0.0.1:46905/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1919240 T5168 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1919241 T5168 oascc.SolrZkClient.makePath makePath: /overseer_elect
   [junit4]   2> 1919242 T5168 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
   [junit4]   2> 1919243 T5168 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:46905_solr
   [junit4]   2> 1919243 T5168 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
   [junit4]   2> 1919244 T5168 oasc.Overseer.start Overseer (id=92249419387895812-127.0.0.1:46905_solr-n_0000000000) starting
   [junit4]   2> 1919245 T5168 oascc.SolrZkClient.makePath makePath: /overseer/queue
   [junit4]   2> 1919247 T5168 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
   [junit4]   2> 1919248 T5168 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-failure
   [junit4]   2> 1919249 T5168 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-running
   [junit4]   2> 1919251 T5168 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-completed
   [junit4]   2> 1919252 T5168 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
   [junit4]   2> 1919254 T5780 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
   [junit4]   2> 1919255 T5779 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
   [junit4]   2> 1919256 T5779 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1919257 T5779 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> 1919257 T5779 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1, shard2, shard3, shard4, shard5, shard6, shard7, shard8, shard9, shard10, shard11, shard12]
   [junit4]   2> 1919257 T5779 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard8
   [junit4]   2> 1919258 T5781 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1919259 T5775 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> 1919259 T5776 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> 1919755 T5168 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard8/election
   [junit4]   2> 1919761 T5168 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard8
   [junit4]   2> 1919764 T5781 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1919764 T5168 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1919767 T5168 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:46905 46905
   [junit4]   2> 1920359 T5762 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:46905 46905
   [junit4]   2> 1920360 T5168 oas.SolrTestCaseJ4.tearDown ###Ending testPlaceholders
   [junit4]   2> 1920360 T5779 oasc.Overseer$ClusterStateUpdater.run Overseer Loop exiting : 127.0.0.1:46905_solr
   [junit4]   2> 1920362 T5782 oasc.Overseer$ClusterStateUpdater.checkIfIamStillLeader ERROR could not read the data org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /overseer_elect/leader
   [junit4]   2> 	at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
   [junit4]   2> 	at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
   [junit4]   2> 	at org.apache.zookeeper.ZooKeeper.getData(ZooKeeper.java:1155)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient$8.execute(SolrZkClient.java:302)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient$8.execute(SolrZkClient.java:299)
   [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:299)
   [junit4]   2> 	at org.apache.solr.cloud.Overseer$ClusterStateUpdater.checkIfIamStillLeader(Overseer.java:317)
   [junit4]   2> 	at org.apache.solr.cloud.Overseer$ClusterStateUpdater.access$300(Overseer.java:85)
   [junit4]   2> 	at org.apache.solr.cloud.Overseer$ClusterStateUpdater$1.run(Overseer.java:289)
   [junit4]   2> 
   [junit4]   2> 1923363 T5168 oas.SolrTestCaseJ4.deleteCore ###deleteCore
   [junit4]   2> NOTE: leaving temporary files on disk at: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./temp/solr.cloud.OverseerTest-B47403706B1EEDE7-001
   [junit4]   2> NOTE: test params are: codec=Lucene49: {}, docValues:{}, sim=RandomSimilarityProvider(queryNorm=false,coord=crazy): {}, locale=ms_MY, timezone=Africa/Juba
   [junit4]   2> NOTE: Linux 3.13.0-32-generic amd64/Oracle Corporation 1.7.0_65 (64-bit)/cpus=8,threads=1,free=113406072,total=325058560
   [junit4]   2> NOTE: All tests run in this JVM: [OverseerCollectionProcessorTest, TestSolrJ, MoreLikeThisHandlerTest, HdfsWriteToMultipleCollectionsTest, RecoveryZkTest, TestAddFieldRealTimeGet, CoreMergeIndexesAdminHandlerTest, AbstractAnalyticsStatsTest, TestDynamicFieldCollectionResource, NoCacheHeaderTest, TestFastOutputStream, BadIndexSchemaTest, TestHighlightDedupGrouping, SSLMigrationTest, TestOverriddenPrefixQueryForCustomFieldType, TestAnalyzedSuggestions, HighlighterConfigTest, MBeansHandlerTest, TestFieldTypeResource, TestSearcherReuse, QueryResultKeyTest, ExpressionTest, AddBlockUpdateTest, DirectSolrSpellCheckerTest, TriLevelCompositeIdRoutingTest, TestCloudManagedSchemaConcurrent, SolrCoreCheckLockOnStartupTest, HdfsBasicDistributedZk2Test, TestExceedMaxTermLength, DOMUtilTest, TestReplicationHandler, TestSolrIndexConfig, WordBreakSolrSpellCheckerTest, TestLRUCache, TestLeaderElectionZkExpiry, SolrIndexSplitterTest, PathHierarchyTokenizerFactoryTest, FieldMutatingUpdateProcessorTest, DocValuesMultiTest, RequiredFieldsTest, FunctionTest, TestManagedSchema, CoreAdminCreateDiscoverTest, TestCloudInspectUtil, TestInfoStreamLogging, RegexBoostProcessorTest, TestBinaryResponseWriter, TestRandomDVFaceting, TestDefaultSimilarityFactory, TestLuceneMatchVersion, TestSuggestSpellingConverter, TestStressReorder, AnalyticsQueryTest, TestFastWriter, TestComponentsName, StandardRequestHandlerTest, BasicFunctionalityTest, ChangedSchemaMergeTest, TestCoreDiscovery, AnalysisErrorHandlingTest, ClusterStateUpdateTest, ResponseHeaderTest, TestJmxIntegration, NotRequiredUniqueKeyTest, TestReloadAndDeleteDocs, TestManagedResourceStorage, MigrateRouteKeyTest, HdfsCollectionsAPIDistributedZkTest, HdfsBasicDistributedZkTest, SimpleFacetsTest, TestSolrDeletionPolicy1, EchoParamsTest, TestTrie, TestManagedSynonymFilterFactory, FastVectorHighlighterTest, TestChildDocTransformer, TestAnalyzeInfixSuggestions, PingRequestHandlerTest, TestMissingGroups, TestDocBasedVersionConstraints, PluginInfoTest, TestDefaultSearchFieldResource, SuggesterTSTTest, DisMaxRequestHandlerTest, ShardRoutingTest, UpdateParamsTest, TestSchemaResource, TestSurroundQueryParser, FieldFacetTest, TestCustomSort, TimeZoneUtilsTest, ParsingFieldUpdateProcessorsTest, ReplicationFactorTest, OpenExchangeRatesOrgProviderTest, TestReRankQParserPlugin, SolrXmlInZkTest, TestFaceting, SuggesterWFSTTest, TestSolrXmlPersistence, TestCodecSupport, SuggesterTest, SuggestComponentTest, TestRTGBase, TestFoldingMultitermQuery, BasicDistributedZkTest, ChaosMonkeySafeLeaderTest, UnloadDistributedZkTest, CollectionsAPIDistributedZkTest, SyncSliceTest, OverseerTest]
   [junit4] Completed on J0 in 70.70s, 9 tests, 1 error <<< FAILURES!

[...truncated 660 lines...]
BUILD FAILED
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/build.xml:474: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/build.xml:454: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/build.xml:45: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/extra-targets.xml:37: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build.xml:189: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/common-build.xml:496: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/lucene/common-build.xml:1298: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/lucene/common-build.xml:922: There were test failures: 421 suites, 1761 tests, 1 error, 39 ignored (18 assumptions)

Total time: 87 minutes 55 seconds
Build step 'Invoke Ant' marked build as failure
[description-setter] Description set: Java: 64bit/jdk1.7.0_65 -XX:+UseCompressedOops -XX:+UseParallelGC
Archiving artifacts
Recording test results
Email was triggered for: Failure - Any
Sending email for trigger: Failure - Any



Mime
View raw message