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-4.x-Windows (32bit/jdk1.7.0_55) - Build # 3904 - Failure!
Date Sat, 26 Apr 2014 10:18:48 GMT
Build: http://jenkins.thetaphi.de/job/Lucene-Solr-4.x-Windows/3904/
Java: 32bit/jdk1.7.0_55 -client -XX:+UseSerialGC

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([76BDF43B2C29134E:72B57BC83E8CFC6F]:0)
	at org.apache.solr.cloud.ShardLeaderElectionContextBase.runLeaderProcess(ElectionContext.java:136)
	at org.apache.solr.cloud.LeaderElector.runIamLeaderProcess(LeaderElector.java:142)
	at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:110)
	at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:134)
	at org.apache.solr.cloud.LeaderElector.joinElection(LeaderElector.java:267)
	at org.apache.solr.cloud.OverseerTest$MockZKController.publishState(OverseerTest.java:155)
	at org.apache.solr.cloud.OverseerTest.testOverseerFailure(OverseerTest.java:661)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:606)
	at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1618)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:827)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:863)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:877)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
	at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:50)
	at org.apache.lucene.util.TestRuleFieldCacheSanity$1.evaluate(TestRuleFieldCacheSanity.java:51)
	at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
	at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:49)
	at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:65)
	at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:360)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:793)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:453)
	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 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:360)
	at java.lang.Thread.run(Thread.java:745)
Caused by: org.apache.solr.common.SolrException: org.apache.zookeeper.KeeperException$NodeExistsException: KeeperErrorCode = NodeExists for /collections/collection1/leaders/shard1
	at org.apache.solr.common.util.RetryUtil.retryOnThrowable(RetryUtil.java:40)
	at org.apache.solr.cloud.ShardLeaderElectionContextBase.runLeaderProcess(ElectionContext.java:123)
	... 46 more
Caused by: org.apache.zookeeper.KeeperException$NodeExistsException: KeeperErrorCode = NodeExists for /collections/collection1/leaders/shard1
	at org.apache.zookeeper.KeeperException.create(KeeperException.java:119)
	at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
	at org.apache.zookeeper.ZooKeeper.create(ZooKeeper.java:783)
	at org.apache.solr.common.cloud.SolrZkClient$10.execute(SolrZkClient.java:432)
	at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
	at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:429)
	at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:386)
	at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:373)
	at org.apache.solr.cloud.ShardLeaderElectionContextBase$1.execute(ElectionContext.java:128)
	at org.apache.solr.common.util.RetryUtil.retryOnThrowable(RetryUtil.java:34)
	... 47 more




Build Log:
[...truncated 11300 lines...]
   [junit4] Suite: org.apache.solr.cloud.OverseerTest
   [junit4]   2> Creating dataDir: C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\solr.cloud.OverseerTest-76BDF43B2C29134E-001\init-core-data-001
   [junit4]   2> 3222568 T9643 oas.SolrTestCaseJ4.buildSSLConfig Randomized ssl (false) and clientAuth (true)
   [junit4]   2> 3222569 T9643 oas.SolrTestCaseJ4.initCore ####initCore
   [junit4]   2> 3222569 T9643 oas.SolrTestCaseJ4.initCore ####initCore end
   [junit4]   2> 3222578 T9643 oas.SolrTestCaseJ4.setUp ###Starting testReplay
   [junit4]   2> 3222581 T9643 oasc.ZkTestServer.run STARTING ZK TEST SERVER
   [junit4]   2> 3222582 T9644 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
   [junit4]   2> 3222683 T9643 oasc.ZkTestServer.run start zk server on port:60138
   [junit4]   2> 3222686 T9643 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 3222697 T9650 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1cd4f56 name:ZooKeeperConnection Watcher:127.0.0.1:60138/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 3222698 T9643 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 3222700 T9643 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 3222705 T9652 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@13e958d name:ZooKeeperConnection Watcher:127.0.0.1:60138 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 3222706 T9643 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 3222716 T9643 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 3222719 T9654 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@6c6ae9 name:ZooKeeperConnection Watcher:127.0.0.1:60138 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 3222720 T9643 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 3222720 T9643 oascc.SolrZkClient.makePath makePath: /solr
   [junit4]   2> 3222733 T9643 oascc.SolrZkClient.makePath makePath: /live_nodes
   [junit4]   2> 3222733 T9645 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x1459d74fbe50002, likely client has closed socket
   [junit4]   2> 	at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:228)
   [junit4]   2> 	at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208)
   [junit4]   2> 	at java.lang.Thread.run(Thread.java:745)
   [junit4]   2> 
   [junit4]   2> 3222740 T9643 oascc.SolrZkClient.makePath makePath: /clusterstate.json
   [junit4]   2> 3222745 T9643 oascc.SolrZkClient.makePath makePath: /aliases.json
   [junit4]   2> 3222748 T9643 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 3222757 T9643 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
   [junit4]   2> 3222770 T9643 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 3222774 T9656 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@b946c2 name:ZooKeeperConnection Watcher:127.0.0.1:60138/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 3222775 T9643 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 3222777 T9643 oascc.SolrZkClient.makePath makePath: /overseer_elect
   [junit4]   2> 3222782 T9643 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
   [junit4]   2> 3222792 T9643 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:60138_solr
   [junit4]   2> 3222793 T9643 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
   [junit4]   2> 3222799 T9643 oasc.Overseer.start Overseer (id=91652493198819331-127.0.0.1:60138_solr-n_0000000000) starting
   [junit4]   2> 3222808 T9643 oascc.SolrZkClient.makePath makePath: /overseer/queue
   [junit4]   2> 3222820 T9643 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-failure
   [junit4]   2> 3222828 T9643 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-running
   [junit4]   2> 3222838 T9643 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-completed
   [junit4]   2> 3222859 T9643 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
   [junit4]   2> 3222875 T9658 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
   [junit4]   2> 3222877 T9658 oasc.OverseerCollectionProcessor.prioritizeOverseerNodes prioritizing overseer nodes at 127.0.0.1:60138_solr
   [junit4]   2> 3222882 T9657 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 3222883 T9657 oasc.Overseer$ClusterStateUpdater.run Replaying operations from work queue.
   [junit4]   2> 3222885 T9657 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> 3222887 T9650 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> 3222896 T9657 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> 3222899 T9650 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> 3222904 T9657 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
   [junit4]   2> 3222912 T9657 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 3222914 T9657 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> 3222923 T9656 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 3222926 T9650 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> 3222983 T9645 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x1459d74fbe50003, likely client has closed socket
   [junit4]   2> 	at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:228)
   [junit4]   2> 	at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208)
   [junit4]   2> 	at java.lang.Thread.run(Thread.java:745)
   [junit4]   2> 
   [junit4]   2> 3222989 T9645 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x1459d74fbe50000, likely client has closed socket
   [junit4]   2> 	at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:228)
   [junit4]   2> 	at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208)
   [junit4]   2> 	at java.lang.Thread.run(Thread.java:745)
   [junit4]   2> 
   [junit4]   2> 3222989 T9643 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:60138 60138
   [junit4]   2> 3225243 T9644 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:60138 60138
   [junit4]   2> 3225248 T9643 oas.SolrTestCaseJ4.tearDown ###Ending testReplay
   [junit4]   2> 3225248 T9657 oasc.Overseer$ClusterStateUpdater.run Overseer Loop exiting : 127.0.0.1:60138_solr
   [junit4]   1> client port:0.0.0.0/0.0.0.0:0
   [junit4]   2> 3225250 T9659 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$7.execute(SolrZkClient.java:277)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:274)
   [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:274)
   [junit4]   2> 	at org.apache.solr.cloud.Overseer$ClusterStateUpdater.checkIfIamStillLeader(Overseer.java:302)
   [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:291)
   [junit4]   2> 
   [junit4]   2> 3225259 T9643 oas.SolrTestCaseJ4.setUp ###Starting testOverseerFailure
   [junit4]   2> 3225261 T9643 oasc.ZkTestServer.run STARTING ZK TEST SERVER
   [junit4]   2> 3225263 T9660 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
   [junit4]   2> 3225364 T9643 oasc.ZkTestServer.run start zk server on port:60153
   [junit4]   2> 3225366 T9643 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 3225373 T9666 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@e8c734 name:ZooKeeperConnection Watcher:127.0.0.1:60153 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 3225373 T9643 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 3225377 T9661 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x1459d7506560000, likely client has closed socket
   [junit4]   2> 	at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:228)
   [junit4]   2> 	at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208)
   [junit4]   2> 	at java.lang.Thread.run(Thread.java:745)
   [junit4]   2> 
   [junit4]   2> 3225379 T9643 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 3225382 T9668 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@26c7ac name:ZooKeeperConnection Watcher:127.0.0.1:60153 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 3225382 T9643 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 3225382 T9643 oascc.SolrZkClient.makePath makePath: /solr
   [junit4]   2> 3225391 T9661 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x1459d7506560001, likely client has closed socket
   [junit4]   2> 	at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:228)
   [junit4]   2> 	at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208)
   [junit4]   2> 	at java.lang.Thread.run(Thread.java:745)
   [junit4]   2> 
   [junit4]   2> 3225393 T9643 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 3225396 T9670 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@830c18 name:ZooKeeperConnection Watcher:127.0.0.1:60153/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 3225396 T9643 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 3225396 T9643 oascc.SolrZkClient.makePath makePath: /live_nodes
   [junit4]   2> 3225402 T9643 oascc.SolrZkClient.makePath makePath: /clusterstate.json
   [junit4]   2> 3225407 T9643 oascc.SolrZkClient.makePath makePath: /aliases.json
   [junit4]   2> 3225412 T9643 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 3225418 T9643 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 3225422 T9672 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@ac8847 name:ZooKeeperConnection Watcher:127.0.0.1:60153/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 3225422 T9643 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 3225424 T9643 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 3225430 T9643 oascc.SolrZkClient.makePath makePath: /live_nodes/node1
   [junit4]   2> 3225437 T9670 oascc.ZkStateReader$3.process Updating live nodes... (1)
   [junit4]   2> 3225438 T9672 oascc.ZkStateReader$3.process Updating live nodes... (1)
   [junit4]   2> 3225440 T9643 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 3225443 T9674 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1dd84a4 name:ZooKeeperConnection Watcher:127.0.0.1:60153/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 3225444 T9643 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 3225445 T9643 oascc.SolrZkClient.makePath makePath: /overseer_elect
   [junit4]   2> 3225452 T9643 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
   [junit4]   2> 3225461 T9643 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:60153_solr
   [junit4]   2> 3225461 T9643 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
   [junit4]   2> 3225467 T9643 oasc.Overseer.start Overseer (id=91652493373997060-127.0.0.1:60153_solr-n_0000000000) starting
   [junit4]   2> 3225473 T9643 oascc.SolrZkClient.makePath makePath: /overseer/queue
   [junit4]   2> 3225481 T9643 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
   [junit4]   2> 3225489 T9643 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-failure
   [junit4]   2> 3225498 T9643 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-running
   [junit4]   2> 3225504 T9643 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-completed
   [junit4]   2> 3225517 T9643 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
   [junit4]   2> 3225533 T9676 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
   [junit4]   2> 3225534 T9676 oasc.OverseerCollectionProcessor.prioritizeOverseerNodes prioritizing overseer nodes at 127.0.0.1:60153_solr
   [junit4]   2> 3225534 T9675 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
   [junit4]   2> 3226539 T9674 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 3226541 T9675 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 3226543 T9675 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> 3226544 T9675 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1]
   [junit4]   2> 3226544 T9675 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
   [junit4]   2> 3226551 T9674 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 3226553 T9670 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> 3226554 T9672 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> 3227039 T9643 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
   [junit4]   2> 3227061 T9643 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 3227076 T9674 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 3227077 T9643 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 3227080 T9675 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 3227084 T9674 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 3227085 T9643 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
   [junit4]   2> 3227091 T9675 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> 3227091 T9675 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
   [junit4]   2> 3227096 T9674 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 3227201 T9670 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> 3227202 T9672 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> 3227256 T9661 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x1459d7506560004, likely client has closed socket
   [junit4]   2> 	at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:228)
   [junit4]   2> 	at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208)
   [junit4]   2> 	at java.lang.Thread.run(Thread.java:745)
   [junit4]   2> 
   [junit4]   2> 3228260 T9643 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
   [junit4]   2> 3228274 T9643 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 3228278 T9678 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@76c76b name:ZooKeeperConnection Watcher:127.0.0.1:60153/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 3228279 T9643 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 3228279 T9675 oasc.Overseer$ClusterStateUpdater.run Overseer Loop exiting : 127.0.0.1:60153_solr
   [junit4]   2> 3228284 T9679 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$7.execute(SolrZkClient.java:277)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:274)
   [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:274)
   [junit4]   2> 	at org.apache.solr.cloud.Overseer$ClusterStateUpdater.checkIfIamStillLeader(Overseer.java:302)
   [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:291)
   [junit4]   2> 
   [junit4]   2> 3228290 T9643 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:60153_solr
   [junit4]   2> 3228291 T9643 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
   [junit4]   2> 3228296 T9643 oasc.Overseer.start Overseer (id=91652493373997061-127.0.0.1:60153_solr-n_0000000001) starting
   [junit4]   2> 3228326 T9681 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
   [junit4]   2> 3228328 T9681 oasc.OverseerCollectionProcessor.prioritizeOverseerNodes prioritizing overseer nodes at 127.0.0.1:60153_solr
   [junit4]   2> 3228328 T9680 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
   [junit4]   2> 3228332 T9680 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 3228333 T9680 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> 3228334 T9680 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
   [junit4]   2> 3228339 T9678 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 3228341 T9672 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> 3228342 T9670 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> 3228403 T9643 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
   [junit4]   2> 3228405 T9678 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 3228408 T9680 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 3228420 T9643 oasc.LeaderElector.checkIfIamLeader WARN Failed setting watch org.apache.zookeeper.KeeperException$NoNodeException: KeeperErrorCode = NoNode for /collections/collection1/leader_elect/shard1/election/91652493373997059-node1_core1-n_0000000001
   [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$7.execute(SolrZkClient.java:277)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:274)
   [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:274)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:127)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector.joinElection(LeaderElector.java:267)
   [junit4]   2> 	at org.apache.solr.cloud.OverseerTest$MockZKController.publishState(OverseerTest.java:155)
   [junit4]   2> 	at org.apache.solr.cloud.OverseerTest.testOverseerFailure(OverseerTest.java:661)
   [junit4]   2> 	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
   [junit4]   2> 	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
   [junit4]   2> 	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
   [junit4]   2> 	at java.lang.reflect.Method.invoke(Method.java:606)
   [junit4]   2> 	at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1618)
   [junit4]   2> 	at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:827)
   [junit4]   2> 	at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:863)
   [junit4]   2> 	at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:877)
   [junit4]   2> 	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
   [junit4]   2> 	at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:50)
   [junit4]   2> 	at org.apache.lucene.util.TestRuleFieldCacheSanity$1.evaluate(TestRuleFieldCacheSanity.java:51)
   [junit4]   2> 	at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
   [junit4]   2> 	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
   [junit4]   2> 	at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:49)
   [junit4]   2> 	at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:65)
   [junit4]   2> 	at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
   [junit4]   2> 	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
   [junit4]   2> 	at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:360)
   [junit4]   2> 	at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:793)
   [junit4]   2> 	at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:453)
   [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 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:360)
   [junit4]   2> 	at java.lang.Thread.run(Thread.java:745)
   [junit4]   2> 
   [junit4]   2> 3228421 T9672 oasc.LeaderElector.checkIfIamLeader WARN Our node is no longer in line to be leader
   [junit4]   2> 3228425 T9680 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:177)
   [junit4]   2> 		at org.apache.solr.common.cloud.SolrZkClient$2.execute(SolrZkClient.java:174)
   [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:174)
   [junit4]   2> 		at org.apache.solr.common.cloud.SolrZkClient.clean(SolrZkClient.java:631)
   [junit4]   2> 		at org.apache.solr.common.cloud.SolrZkClient.clean(SolrZkClient.java:626)
   [junit4]   2> 		at org.apache.solr.common.cloud.SolrZkClient.clean(SolrZkClient.java:626)
   [junit4]   2> 		at org.apache.solr.common.cloud.SolrZkClient.clean(SolrZkClient.java:626)
   [junit4]   2> 		at org.apache.solr.cloud.Overseer$ClusterStateUpdater.removeCore(Overseer.java:1069)
   [junit4]   2> 		at org.apache.solr.cloud.Overseer$ClusterStateUpdater.processMessage(Overseer.java:342)
   [junit4]   2> 		at org.apache.solr.cloud.Overseer$ClusterStateUpdater.run(Overseer.java:241)
   [junit4]   2> 		at java.lang.Thread.run(Thread.java:745)
   [junit4]   2> 	
   [junit4]   2> 3228428 T9643 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 3228429 T9672 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 3228433 T9678 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 3228443 T9678 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 3228445 T9680 oasc.Overseer$ClusterStateUpdater.setShardLeader ERROR Could not mark shard leader for non existing collection:collection1
   [junit4]   2> 3228452 T9678 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 3228555 T9672 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> 3228556 T9670 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> 3229438 T9643 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 3230444 T9643 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 3231480 T9643 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 3232586 T9643 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 3233692 T9643 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 3234800 T9643 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 3235907 T9643 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 3237017 T9643 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 3238133 T9643 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 3239240 T9643 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 3240349 T9643 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 3241458 T9643 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 3242526 T9643 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 3243522 T9643 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 3244518 T9643 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 3244528 T9670 oascc.ZkStateReader$3.process Updating live nodes... (0)
   [junit4]   2> 3244528 T9672 oascc.ZkStateReader$3.process Updating live nodes... (0)
   [junit4]   2> 3244530 T9661 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x1459d7506560003, likely client has closed socket
   [junit4]   2> 	at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:228)
   [junit4]   2> 	at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208)
   [junit4]   2> 	at java.lang.Thread.run(Thread.java:745)
   [junit4]   2> 
   [junit4]   2> 3244534 T9661 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x1459d7506560005, likely client has closed socket
   [junit4]   2> 	at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:228)
   [junit4]   2> 	at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208)
   [junit4]   2> 	at java.lang.Thread.run(Thread.java:745)
   [junit4]   2> 
   [junit4]   2> 3244540 T9643 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:60153 60153
   [junit4]   2> 3246771 T9660 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:60153 60153
   [junit4]   2> 3246774 T9643 oas.SolrTestCaseJ4.tearDown ###Ending testOverseerFailure
   [junit4]   2> 3246775 T9680 oasc.Overseer$ClusterStateUpdater.run Overseer Loop exiting : 127.0.0.1:60153_solr
   [junit4]   2> 3246776 T9682 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$7.execute(SolrZkClient.java:277)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:274)
   [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:274)
   [junit4]   2> 	at org.apache.solr.cloud.Overseer$ClusterStateUpdater.checkIfIamStillLeader(Overseer.java:302)
   [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:291)
   [junit4]   2> 
   [junit4]   1> client port:0.0.0.0/0.0.0.0:0
   [junit4]   2> NOTE: reproduce with: ant test  -Dtestcase=OverseerTest -Dtests.method=testOverseerFailure -Dtests.seed=76BDF43B2C29134E -Dtests.slow=true -Dtests.locale=vi_VN -Dtests.timezone=Antarctica/DumontDUrville -Dtests.file.encoding=US-ASCII
   [junit4] ERROR   21.5s | 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([76BDF43B2C29134E:72B57BC83E8CFC6F]:0)
   [junit4]    > 	at org.apache.solr.cloud.ShardLeaderElectionContextBase.runLeaderProcess(ElectionContext.java:136)
   [junit4]    > 	at org.apache.solr.cloud.LeaderElector.runIamLeaderProcess(LeaderElector.java:142)
   [junit4]    > 	at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:110)
   [junit4]    > 	at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:134)
   [junit4]    > 	at org.apache.solr.cloud.LeaderElector.joinElection(LeaderElector.java:267)
   [junit4]    > 	at org.apache.solr.cloud.OverseerTest$MockZKController.publishState(OverseerTest.java:155)
   [junit4]    > 	at org.apache.solr.cloud.OverseerTest.testOverseerFailure(OverseerTest.java:661)
   [junit4]    > 	at java.lang.Thread.run(Thread.java:745)
   [junit4]    > Caused by: org.apache.solr.common.SolrException: org.apache.zookeeper.KeeperException$NodeExistsException: KeeperErrorCode = NodeExists for /collections/collection1/leaders/shard1
   [junit4]    > 	at org.apache.solr.common.util.RetryUtil.retryOnThrowable(RetryUtil.java:40)
   [junit4]    > 	at org.apache.solr.cloud.ShardLeaderElectionContextBase.runLeaderProcess(ElectionContext.java:123)
   [junit4]    > 	... 46 more
   [junit4]    > Caused by: org.apache.zookeeper.KeeperException$NodeExistsException: KeeperErrorCode = NodeExists for /collections/collection1/leaders/shard1
   [junit4]    > 	at org.apache.zookeeper.KeeperException.create(KeeperException.java:119)
   [junit4]    > 	at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
   [junit4]    > 	at org.apache.zookeeper.ZooKeeper.create(ZooKeeper.java:783)
   [junit4]    > 	at org.apache.solr.common.cloud.SolrZkClient$10.execute(SolrZkClient.java:432)
   [junit4]    > 	at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
   [junit4]    > 	at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:429)
   [junit4]    > 	at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:386)
   [junit4]    > 	at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:373)
   [junit4]    > 	at org.apache.solr.cloud.ShardLeaderElectionContextBase$1.execute(ElectionContext.java:128)
   [junit4]    > 	at org.apache.solr.common.util.RetryUtil.retryOnThrowable(RetryUtil.java:34)
   [junit4]    > 	... 47 more
   [junit4]   2> 3246793 T9643 oas.SolrTestCaseJ4.setUp ###Starting testShardLeaderChange
   [junit4]   2> 3246795 T9643 oasc.ZkTestServer.run STARTING ZK TEST SERVER
   [junit4]   2> 3246796 T9683 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
   [junit4]   2> 3246896 T9643 oasc.ZkTestServer.run start zk server on port:60174
   [junit4]   2> 3246898 T9643 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 3246904 T9689 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@19c0bc5 name:ZooKeeperConnection Watcher:127.0.0.1:60174/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 3246904 T9643 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 3246906 T9643 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 3246908 T9691 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@14cf2ff name:ZooKeeperConnection Watcher:127.0.0.1:60174 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 3246909 T9643 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 3246913 T9684 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x1459d755a720001, likely client has closed socket
   [junit4]   2> 	at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:228)
   [junit4]   2> 	at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208)
   [junit4]   2> 	at java.lang.Thread.run(Thread.java:745)
   [junit4]   2> 
   [junit4]   2> 3246914 T9643 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 3246916 T9693 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@18f5e9d name:ZooKeeperConnection Watcher:127.0.0.1:60174 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 3246917 T9643 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 3246917 T9643 oascc.SolrZkClient.makePath makePath: /solr
   [junit4]   2> 3246924 T9643 oascc.SolrZkClient.makePath makePath: /live_nodes
   [junit4]   2> 3246924 T9684 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x1459d755a720002, likely client has closed socket
   [junit4]   2> 	at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:228)
   [junit4]   2> 	at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208)
   [junit4]   2> 	at java.lang.Thread.run(Thread.java:745)
   [junit4]   2> 
   [junit4]   2> 3246932 T9694 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 3246932 T9643 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 3246934 T9697 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@ef8cac name:ZooKeeperConnection Watcher:127.0.0.1:60174/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 3246935 T9694 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 3246935 T9698 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@12623c name:ZooKeeperConnection Watcher:127.0.0.1:60174/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 3246935 T9643 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 3246936 T9694 oascc.SolrZkClient.makePath makePath: /overseer_elect
   [junit4]   2> 3246936 T9643 oascc.SolrZkClient.makePath makePath: /clusterstate.json
   [junit4]   2> 3246940 T9694 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
   [junit4]   2> 3246940 T9643 oascc.SolrZkClient.makePath makePath: /aliases.json
   [junit4]   2> 3246944 T9643 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 3246949 T9694 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:60174_solr
   [junit4]   2> 3246949 T9694 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
   [junit4]   2> 3246951 T9643 oascc.SolrZkClient.makePath makePath: /live_nodes/node1
   [junit4]   2> 3246954 T9694 oasc.Overseer.start Overseer (id=91652494785118211-127.0.0.1:60174_solr-n_0000000000) starting
   [junit4]   2> 3246956 T9698 oascc.ZkStateReader$3.process Updating live nodes... (1)
   [junit4]   2> 3246959 T9643 oascc.SolrZkClient.makePath makePath: /overseer/queue
   [junit4]   2> 3246960 T9694 oascc.SolrZkClient.makePath makePath: /overseer/queue
   [junit4]   2> 3246966 T9694 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
   [junit4]   2> 3246974 T9694 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-failure
   [junit4]   2> 3246983 T9694 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-running
   [junit4]   2> 3246989 T9694 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-completed
   [junit4]   2> 3246994 T9694 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
   [junit4]   2> 3247005 T9694 oasc.OverseerTest$OverseerRestarter.run Killing overseer.
   [junit4]   2> 3247005 T9700 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
   [junit4]   2> 3247010 T9694 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 3247012 T9702 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1cfa121 name:ZooKeeperConnection Watcher:127.0.0.1:60174/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 3247013 T9694 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 3247013 T9700 oasc.OverseerCollectionProcessor.amILeader According to ZK I (id=91652494785118211-127.0.0.1:60174_solr-n_0000000000) am no longer a leader.
   [junit4]   2> 3247015 T9700 oasc.OverseerCollectionProcessor.prioritizeOverseerNodes prioritizing overseer nodes at 127.0.0.1:60174_solr
   [junit4]   2> 3247015 T9700 oasc.OverseerCollectionProcessor.run ERROR Unable to prioritize overseer  org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /roles.json
   [junit4]   2> 	at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
   [junit4]   2> 	at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
   [junit4]   2> 	at org.apache.zookeeper.ZooKeeper.exists(ZooKeeper.java:1045)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient$4.execute(SolrZkClient.java:226)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient$4.execute(SolrZkClient.java:223)
   [junit4]   2> 	at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient.exists(SolrZkClient.java:223)
   [junit4]   2> 	at org.apache.solr.cloud.OverseerCollectionProcessor.prioritizeOverseerNodes(OverseerCollectionProcessor.java:299)
   [junit4]   2> 	at org.apache.solr.cloud.OverseerCollectionProcessor.run(OverseerCollectionProcessor.java:212)
   [junit4]   2> 	at java.lang.Thread.run(Thread.java:745)
   [junit4]   2> 
   [junit4]   2> 3247020 T9694 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:60174_solr
   [junit4]   2> 3247021 T9694 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
   [junit4]   2> 3247024 T9694 oasc.Overseer.start Overseer (id=91652494785118213-127.0.0.1:60174_solr-n_0000000001) starting
   [junit4]   2> 3247045 T9704 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
   [junit4]   2> 3247047 T9704 oasc.OverseerCollectionProcessor.prioritizeOverseerNodes prioritizing overseer nodes at 127.0.0.1:60174_solr
   [junit4]   2> 3247047 T9703 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
   [junit4]   2> 3247050 T9703 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 3247051 T9703 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"state1",
   [junit4]   2> 	  "node_name":"node1",
   [junit4]   2> 	  "core":"core1",
   [junit4]   2> 	  "core_node_name":"node1",
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "numShards":"1",
   [junit4]   2> 	  "base_url":"http://node1/solr/"}
   [junit4]   2> 3247051 T9703 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1]
   [junit4]   2> 3247051 T9703 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
   [junit4]   2> 3247056 T9702 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 3247058 T9698 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> 3247459 T9643 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
   [junit4]   2> 3247479 T9643 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 3247490 T9702 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 3247496 T9643 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
   [junit4]   2> 3247496 T9702 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 3247497 T9703 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 3247508 T9703 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"state2",
   [junit4]   2> 	  "node_name":"node1",
   [junit4]   2> 	  "core":"core1",
   [junit4]   2> 	  "core_node_name":"node1",
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "numShards":"1",
   [junit4]   2> 	  "base_url":"http://node1/solr/"}
   [junit4]   2> 3247509 T9703 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
   [junit4]   2> 3247513 T9702 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 3247514 T9643 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 3247516 T9706 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1b12ff9 name:ZooKeeperConnection Watcher:127.0.0.1:60174/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 3247517 T9643 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 3247519 T9643 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 3247523 T9643 oascc.SolrZkClient.makePath makePath: /live_nodes/node2
   [junit4]   2> 3247528 T9698 oascc.ZkStateReader$3.process Updating live nodes... (2)
   [junit4]   2> 3247529 T9706 oascc.ZkStateReader$3.process Updating live nodes... (2)
   [junit4]   2> 3247533 T9643 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
   [junit4]   2> 3247533 T9702 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 3247535 T9703 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"state1",
   [junit4]   2> 	  "node_name":"node1",
   [junit4]   2> 	  "core":"core1",
   [junit4]   2> 	  "core_node_name":"node1",
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "numShards":"1",
   [junit4]   2> 	  "base_url":"http://node1/solr/"}
   [junit4]   2> 3247536 T9703 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
   [junit4]   2> 3247542 T9702 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 3247545 T9643 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 3247649 T9706 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
   [junit4]   2> 3247649 T9698 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
   [junit4]   2> 3247748 T9643 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 3247758 T9702 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 3247758 T9702 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 3247758 T9702 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 3247761 T9703 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 3247763 T9703 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"state2",
   [junit4]   2> 	  "node_name":"node2",
   [junit4]   2> 	  "core":"core4",
   [junit4]   2> 	  "core_node_name":"node2",
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "numShards":"1",
   [junit4]   2> 	  "base_url":"http://node2/solr/"}
   [junit4]   2> 3247763 T9703 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=1
   [junit4]   2> 3247763 T9703 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
   [junit4]   2> 3247769 T9702 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 3247872 T9698 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
   [junit4]   2> 3247873 T9706 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
   [junit4]   2> 3248253 T9643 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
   [junit4]   2> 3248268 T9706 oascc.ZkStateReader$3.process Updating live nodes... (1)
   [junit4]   2> 3248269 T9698 oascc.ZkStateReader$3.process Updating live nodes... (1)
   [junit4]   2> 3248271 T9698 oasc.LeaderElector$ElectionWatcher.process WARN  org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /collections/collection1/leader_elect/shard1/election
   [junit4]   2> 	at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
   [junit4]   2> 	at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
   [junit4]   2> 	at org.apache.zookeeper.ZooKeeper.getChildren(ZooKeeper.java:1472)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:260)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:257)
   [junit4]   2> 	at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient.getChildren(SolrZkClient.java:257)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:94)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector.access$200(LeaderElector.java:55)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector$ElectionWatcher.process(LeaderElector.java:303)
   [junit4]   2> 	at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:522)
   [junit4]   2> 	at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:498)
   [junit4]   2> 
   [junit4]   2> 3248272 T9643 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 3248272 T9698 oasc.LeaderElector$ElectionWatcher.process WARN  org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /collections/collection1/leader_elect/shard1/election
   [junit4]   2> 	at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
   [junit4]   2> 	at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
   [junit4]   2> 	at org.apache.zookeeper.ZooKeeper.getChildren(ZooKeeper.java:1472)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:260)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:257)
   [junit4]   2> 	at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient.getChildren(SolrZkClient.java:257)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:94)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector.access$200(LeaderElector.java:55)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector$ElectionWatcher.process(LeaderElector.java:303)
   [junit4]   2> 	at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:522)
   [junit4]   2> 	at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:498)
   [junit4]   2> 
   [junit4]   2> 3248273 T9706 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 3248284 T9702 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 3248285 T9702 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 3248285 T9702 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 3248288 T9703 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 3248297 T9702 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 3248401 T9706 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> 3248473 T9643 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 3248477 T9643 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 3248479 T9708 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@2e0773 name:ZooKeeperConnection Watcher:127.0.0.1:60174/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 3248480 T9643 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 3248482 T9643 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 3248487 T9643 oascc.SolrZkClient.makePath makePath: /live_nodes/node1
   [junit4]   2> 3248493 T9708 oascc.ZkStateReader$3.process Updating live nodes... (2)
   [junit4]   2> 3248494 T9706 oascc.ZkStateReader$3.process Updating live nodes... (2)
   [junit4]   2> 3248499 T9643 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
   [junit4]   2> 3248500 T9702 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 3248500 T9702 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 3248501 T9702 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 3248506 T9703 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 3248507 T9703 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"state1",
   [junit4]   2> 	  "node_name":"node1",
   [junit4]   2> 	  "core":"core1",
   [junit4]   2> 	  "core_node_name":"node1",
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "numShards":"1",
   [junit4]   2> 	  "base_url":"http://node1/solr/"}
   [junit4]   2> 3248508 T9703 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
   [junit4]   2> 3248515 T9702 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 3248519 T9706 oascc.ZkStateReader$3.process Updating live nodes... (1)
   [junit4]   2> 3248519 T9708 oascc.ZkStateReader$3.process Updating live nodes... (1)
   [junit4]   2> 3248525 T9708 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 3248527 T9643 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
   [junit4]   2> 3248528 T9702 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 3248533 T9703 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"state2",
   [junit4]   2> 	  "node_name":"node1",
   [junit4]   2> 	  "core":"core1",
   [junit4]   2> 	  "core_node_name":"node1",
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "numShards":"1",
   [junit4]   2> 	  "base_url":"http://node1/solr/"}
   [junit4]   2> 3248533 T9703 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
   [junit4]   2> 3248538 T9694 oasc.OverseerTest$OverseerRestarter.run Killing overseer.
   [junit4]   2> 3248543 T9702 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 3248547 T9694 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 3248551 T9643 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 3248553 T9710 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@12a3d98 name:ZooKeeperConnection Watcher:127.0.0.1:60174/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 3248554 T9694 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 3248556 T9712 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@e922c7 name:ZooKeeperConnection Watcher:127.0.0.1:60174/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 3248556 T9703 oasc.Overseer$ClusterStateUpdater.run Overseer Loop exiting : 127.0.0.1:60174_solr
   [junit4]   2> 3248557 T9643 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 3248558 T9713 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$7.execute(SolrZkClient.java:277)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:274)
   [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:274)
   [junit4]   2> 	at org.apache.solr.cloud.Overseer$ClusterStateUpdater.checkIfIamStillLeader(Overseer.java:302)
   [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:291)
   [junit4]   2> 
   [junit4]   2> 3248563 T9643 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 3248566 T9694 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:60174_solr
   [junit4]   2> 3248567 T9694 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
   [junit4]   2> 3248570 T9643 oascc.SolrZkClient.makePath makePath: /live_nodes/node2
   [junit4]   2> 3248572 T9694 oasc.Overseer.start Overseer (id=91652494785118216-127.0.0.1:60174_solr-n_0000000002) starting
   [junit4]   2> 3248582 T9708 oascc.ZkStateReader$3.process Updating live nodes... (2)
   [junit4]   2> 3248583 T9712 oascc.ZkStateReader$3.process Updating live nodes... (2)
   [junit4]   2> 3248589 T9643 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
   [junit4]   2> 3248608 T9643 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 3248611 T9715 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
   [junit4]   2> 3248613 T9715 oasc.OverseerCollectionProcessor.prioritizeOverseerNodes prioritizing overseer nodes at 127.0.0.1:60174_solr
   [junit4]   2> 3248615 T9714 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 3248617 T9714 oasc.Overseer$ClusterStateUpdater.run Replaying operations from work queue.
   [junit4]   2> 3248619 T9714 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"state1",
   [junit4]   2> 	  "node_name":"node1",
   [junit4]   2> 	  "core":"core1",
   [junit4]   2> 	  "core_node_name":"node1",
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "numShards":"1",
   [junit4]   2> 	  "base_url":"http://node1/solr/"}
   [junit4]   2> 3248619 T9714 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
   [junit4]   2> 3248622 T9712 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
   [junit4]   2> 3248622 T9708 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
   [junit4]   2> 3248628 T9714 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"state2",
   [junit4]   2> 	  "node_name":"node1",
   [junit4]   2> 	  "core":"core1",
   [junit4]   2> 	  "core_node_name":"node1",
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "numShards":"1",
   [junit4]   2> 	  "base_url":"http://node1/solr/"}
   [junit4]   2> 3248628 T9714 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
   [junit4]   2> 3248630 T9708 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
   [junit4]   2> 3248630 T9712 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
   [junit4]   2> 3248636 T9714 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
   [junit4]   2> 3248640 T9714 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 3248642 T9714 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"state2",
   [junit4]   2> 	  "node_name":"node1",
   [junit4]   2> 	  "core":"core1",
   [junit4]   2> 	  "core_node_name":"node1",
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "numShards":"1",
   [junit4]   2> 	  "base_url":"http://node1/solr/"}
   [junit4]   2> 3248642 T9714 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
   [junit4]   2> 3248648 T9710 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 3248650 T9712 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
   [junit4]   2> 3248650 T9708 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
   [junit4]   2> 3248655 T9714 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 3248662 T9710 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 3248664 T9714 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"state1",
   [junit4]   2> 	  "node_name":"node1",
   [junit4]   2> 	  "core":"core1",
   [junit4]   2> 	  "core_node_name":"node1",
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "numShards":"1",
   [junit4]   2> 	  "base_url":"http://node1/solr/"}
   [junit4]   2> 3248665 T9714 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
   [junit4]   2> 3248671 T9710 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 3248773 T9708 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
   [junit4]   2> 3248773 T9712 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
   [junit4]   2> 3248809 T9643 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 3248816 T9710 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 3248817 T9710 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 3248816 T9643 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
   [junit4]   2> 3248817 T9710 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 3248821 T9714 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 3248822 T9714 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"state2",
   [junit4]   2> 	  "node_name":"node2",
   [junit4]   2> 	  "core":"core4",
   [junit4]   2> 	  "core_node_name":"node2",
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "numShards":"1",
   [junit4]   2> 	  "base_url":"http://node2/solr/"}
   [junit4]   2> 3248822 T9714 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
   [junit4]   2> 3248832 T9710 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 3248838 T9712 oascc.ZkStateReader$3.process Updating live nodes... (1)
   [junit4]   2> 3248842 T9643 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 3248844 T9712 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 3248856 T9710 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 3248865 T9710 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 3248969 T9712 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> 3249044 T9643 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 3249048 T9643 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 3249051 T9717 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@6805e8 name:ZooKeeperConnection Watcher:127.0.0.1:60174/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 3249052 T9643 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 3249055 T9643 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 3249061 T9643 oascc.SolrZkClient.makePath makePath: /live_nodes/node1
   [junit4]   2> 3249071 T9717 oascc.ZkStateReader$3.process Updating live nodes... (2)
   [junit4]   2> 3249072 T9712 oascc.ZkStateReader$3.process Updating live nodes... (2)
   [junit4]   2> 3249077 T9643 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
   [junit4]   2> 3249077 T9710 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 3249078 T9710 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 3249079 T9710 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 3249083 T9714 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 3249087 T9714 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"state1",
   [junit4]   2> 	  "node_name":"node1",
   [junit4]   2> 	  "core":"core1",
   [junit4]   2> 	  "core_node_name":"node1",
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "numShards":"1",
   [junit4]   2> 	  "base_url":"http://node1/solr/"}
   [junit4]   2> 3249088 T9714 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
   [junit4]   2> 3249098 T9710 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 3249098 T9717 oascc.ZkStateReader$3.process Updating live nodes... (1)
   [junit4]   2> 3249100 T9684 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x1459d755a720009, likely client has closed socket
   [junit4]   2> 	at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:228)
   [junit4]   2> 	at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208)
   [junit4]   2> 	at java.lang.Thread.run(Thread.java:745)
   [junit4]   2> 
   [junit4]   2> 3249104 T9717 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 3249107 T9643 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
   [junit4]   2> 3249107 T9710 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 3249109 T9694 oasc.OverseerTest$OverseerRestarter.run Killing overseer.
   [junit4]   2> 3249115 T9694 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 3249120 T9719 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@2cca12 name:ZooKeeperConnection Watcher:127.0.0.1:60174/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 3249120 T9694 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 3249122 T9714 oasc.Overseer$ClusterStateUpdater.run Overseer Loop exiting : 127.0.0.1:60174_solr
   [junit4]   2> 3249124 T9720 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$7.execute(SolrZkClient.java:277)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:274)
   [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:274)
   [junit4]   2> 	at org.apache.solr.cloud.Overseer$ClusterStateUpdater.checkIfIamStillLeader(Overseer.java:302)
   [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:291)
   [junit4]   2> 
   [junit4]   2> 3249134 T9694 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:60174_solr
   [junit4]   2> 3249134 T9694 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
   [junit4]   2> 3249136 T9643 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 3249140 T9694 oasc.Overseer.start Overseer (id=91652494785118219-127.0.0.1:60174_solr-n_0000000003) starting
   [junit4]   2> 3249142 T9722 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@27646f name:ZooKeeperConnection Watcher:127.0.0.1:60174/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 3249143 T9643 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 3249146 T9643 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 3249154 T9643 oascc.SolrZkClient.makePath makePath: /live_nodes/node2
   [junit4]   2> 3249163 T9717 oascc.ZkStateReader$3.process Updating live nodes... (2)
   [junit4]   2> 3249163 T9722 oascc.ZkStateReader$3.process Updating live nodes... (2)
   [junit4]   2> 3249170 T9643 oascc.SolrZkClient.makePath makePath: /collect

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

4]   2> 3284981 T9941 oasc.LeaderElector$ElectionWatcher.process WARN  org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /collections/collection1/leader_elect/shard8/election
   [junit4]   2> 	at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
   [junit4]   2> 	at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
   [junit4]   2> 	at org.apache.zookeeper.ZooKeeper.getChildren(ZooKeeper.java:1472)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:260)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:257)
   [junit4]   2> 	at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient.getChildren(SolrZkClient.java:257)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:94)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector.access$200(LeaderElector.java:55)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector$ElectionWatcher.process(LeaderElector.java:303)
   [junit4]   2> 	at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:522)
   [junit4]   2> 	at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:498)
   [junit4]   2> 
   [junit4]   2> 3284079 T9989 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
   [junit4]   2> 3283802 T9953 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
   [junit4]   2> 3284983 T9825 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:60315 60315
   [junit4]   2> 3284990 T9643 oas.SolrTestCaseJ4.tearDown ###Ending testShardAssignmentBigger
   [junit4]   2> 3284991 T9838 oasc.Overseer$ClusterStateUpdater.run Overseer Loop exiting : 127.0.0.1:60315_solr
   [junit4]   1> client port:0.0.0.0/0.0.0.0:0
   [junit4]   2> 3284992 T10116 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$7.execute(SolrZkClient.java:277)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:274)
   [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:274)
   [junit4]   2> 	at org.apache.solr.cloud.Overseer$ClusterStateUpdater.checkIfIamStillLeader(Overseer.java:302)
   [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:291)
   [junit4]   2> 
   [junit4]   2> 3284994 T9643 oas.SolrTestCaseJ4.initCore ####initCore
   [junit4]   2> 3284996 T9643 oas.SolrTestCaseJ4.initCore ####initCore end
   [junit4]   2> 3287996 T9643 oas.SolrTestCaseJ4.deleteCore ###deleteCore
   [junit4]   2> NOTE: leaving temporary files on disk at: C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\solr.cloud.OverseerTest-76BDF43B2C29134E-001
   [junit4]   2> NOTE: test params are: codec=CheapBastard, sim=RandomSimilarityProvider(queryNorm=true,coord=crazy): {}, locale=vi_VN, timezone=Antarctica/DumontDUrville
   [junit4]   2> NOTE: Windows 7 6.1 x86/Oracle Corporation 1.7.0_55 (32-bit)/cpus=2,threads=1,free=211376464,total=443068416
   [junit4]   2> NOTE: All tests run in this JVM: [TestNoOpRegenerator, SyncSliceTest, TestSweetSpotSimilarityFactory, DocumentBuilderTest, ShardSplitTest, TestDefaultSimilarityFactory, LukeRequestHandlerTest, SuggesterTest, DeleteInactiveReplicaTest, SuggestComponentTest, SampleTest, CoreAdminCreateDiscoverTest, SignatureUpdateProcessorFactoryTest, CustomCollectionTest, TestStressVersions, FullSolrCloudDistribCmdsTest, QueryParsingTest, RemoteQueryErrorTest, TestRTGBase, TestStressRecovery, TestDistributedGrouping, TestReplicationHandler, HardAutoCommitTest, TestInfoStreamLogging, XmlUpdateRequestHandlerTest, DirectUpdateHandlerTest, BasicFunctionalityTest, ChaosMonkeySafeLeaderTest, TestDynamicFieldResource, TestJmxIntegration, SOLR749Test, WordBreakSolrSpellCheckerTest, TestFieldResource, TestPerFieldSimilarity, TestDistributedMissingSort, UUIDFieldTest, TestSchemaSimilarityResource, RequestHandlersTest, TestRequestStatusCollectionAPI, TestGroupingSearch, TestHighlightDedupGrouping, CursorPagingTest, TestRestManager, QueryElevationComponentTest, HdfsBasicDistributedZk2Test, TestAddFieldRealTimeGet, StandardRequestHandlerTest, AnalysisErrorHandlingTest, TestFieldCollectionResource, ResponseLogComponentTest, TestRandomDVFaceting, TestManagedSchema, TestMiniSolrCloudCluster, TestComplexPhraseQParserPlugin, TestAnalyzedSuggestions, DeleteShardTest, SoftAutoCommitTest, NumericFieldsTest, SolrTestCaseJ4Test, TestFileDictionaryLookup, TestImplicitCoreProperties, TestPostingsSolrHighlighter, SuggesterWFSTTest, JsonLoaderTest, TestLazyCores, RegexBoostProcessorTest, TestManagedResource, SolrIndexConfigTest, TestNumberUtils, DeleteReplicaTest, LeaderElectionTest, ZkCLITest, ConnectionManagerTest, TestZkChroot, DistributedQueryComponentCustomSortTest, BlockDirectoryTest, TestFieldTypeCollectionResource, TestSchemaNameResource, MigrateRouteKeyTest, DocValuesTest, TestCSVResponseWriter, TestManagedResourceStorage, TestPHPSerializedResponseWriter, TestReloadAndDeleteDocs, DistributedQueryComponentOptimizationTest, SpatialFilterTest, ClusterStateUpdateTest, BinaryUpdateRequestHandlerTest, SortByFunctionTest, TestBlendedInfixSuggestions, FileBasedSpellCheckerTest, PreAnalyzedFieldTest, TestSystemIdResolver, CoreAdminHandlerTest, LeaderElectionIntegrationTest, RAMDirectoryFactoryTest, ConvertedLegacyTest, FastVectorHighlighterTest, CSVRequestHandlerTest, ChangedSchemaMergeTest, BasicDistributedZkTest, TestSort, OverseerStatusTest, UnloadDistributedZkTest, TestSolrCoreProperties, TestBadConfig, TestHashPartitioner, DirectSolrConnectionTest, TestDFRSimilarityFactory, DocumentAnalysisRequestHandlerTest, TestExpandComponent, TestJoin, TestCoreContainer, TestOverriddenPrefixQueryForCustomFieldType, TestStressReorder, MoreLikeThisHandlerTest, TestRecoveryHdfs, SolrCoreCheckLockOnStartupTest, SpellCheckComponentTest, JSONWriterTest, URLClassifyProcessorTest, MBeansHandlerTest, AutoCommitTest, TestRemoteStreaming, TestOmitPositions, CopyFieldTest, TestCoreDiscovery, TestShardHandlerFactory, DisMaxRequestHandlerTest, TestSolrQueryParserDefaultOperatorResource, TestDocBasedVersionConstraints, TermVectorComponentTest, DateMathParserTest, PathHierarchyTokenizerFactoryTest, ChaosMonkeyNothingIsSafeTest, TestQuerySenderNoQuery, PolyFieldTest, CurrencyFieldXmlFileTest, CoreAdminRequestStatusTest, TestDocumentBuilder, SchemaVersionSpecificBehaviorTest, TestConfigSets, TestLMJelinekMercerSimilarityFactory, ShardRoutingTest, TestLuceneMatchVersion, ReturnFieldsTest, ZkControllerTest, TriLevelCompositeIdRoutingTest, DateFieldTest, DistributedQueryElevationComponentTest, RecoveryZkTest, TestSchemaVersionResource, TestSolrQueryParserResource, TestPseudoReturnFields, TestAnalyzeInfixSuggestions, PrimUtilsTest, PingRequestHandlerTest, PeerSyncTest, TestAtomicUpdateErrorCases, TestCopyFieldCollectionResource, TestDefaultSearchFieldResource, TestSchemaResource, QueryResultKeyTest, TestStandardQParsers, DistributedExpandComponentTest, TestRandomFaceting, DocExpirationUpdateProcessorFactoryTest, NoCacheHeaderTest, TestManagedSchemaFieldResource, SynonymTokenizerTest, AnalysisAfterCoreReloadTest, TestFreeTextSuggestions, ParsingFieldUpdateProcessorsTest, OpenCloseCoreStressTest, TestFaceting, TestDistributedSearch, TestStressUserVersions, TestFiltering, AsyncMigrateRouteKeyTest, IndexSchemaTest, IndexBasedSpellCheckerTest, TestWriterPerf, ZkSolrClientTest, TestUtils, TestRangeQuery, TestSolrJ, HdfsWriteToMultipleCollectionsTest, TestUniqueKeyFieldResource, BasicDistributedZk2Test, CollectionsAPIDistributedZkTest, OverseerTest]
   [junit4] Completed in 65.49s, 9 tests, 1 error <<< FAILURES!

[...truncated 605 lines...]
BUILD FAILED
C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\build.xml:467: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\build.xml:447: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\build.xml:45: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\extra-targets.xml:37: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build.xml:189: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\common-build.xml:496: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\lucene\common-build.xml:1297: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\lucene\common-build.xml:921: There were test failures: 389 suites, 1626 tests, 1 error, 42 ignored (21 assumptions)

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



Mime
View raw message