lucene-dev mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From Policeman Jenkins Server <jenk...@thetaphi.de>
Subject [JENKINS] Lucene-Solr-trunk-Windows (32bit/jdk1.7.0_60-ea-b14) - Build # 3997 - Still Failing!
Date Thu, 01 May 2014 04:04:02 GMT
Build: http://jenkins.thetaphi.de/job/Lucene-Solr-trunk-Windows/3997/
Java: 32bit/jdk1.7.0_60-ea-b14 -client -XX:+UseConcMarkSweepGC

1 tests failed.
FAILED:  org.apache.solr.cloud.OverseerTest.testOverseerFailure

Error Message:
Could not register as the leader because creating the ephemeral registration node in ZooKeeper failed

Stack Trace:
org.apache.solr.common.SolrException: Could not register as the leader because creating the ephemeral registration node in ZooKeeper failed
	at __randomizedtesting.SeedInfo.seed([B9959006173984F3:BD9D1FF5059C6BD2]: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 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:744)
Caused by: org.apache.zookeeper.KeeperException$NodeExistsException: KeeperErrorCode = NodeExists for /collections/collection1/leaders/shard1
	at org.apache.zookeeper.KeeperException.create(KeeperException.java:119)
	at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
	at org.apache.zookeeper.ZooKeeper.create(ZooKeeper.java:783)
	at org.apache.solr.common.cloud.SolrZkClient$10.execute(SolrZkClient.java: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:31)
	at org.apache.solr.cloud.ShardLeaderElectionContextBase.runLeaderProcess(ElectionContext.java:123)
	... 47 more




Build Log:
[...truncated 11121 lines...]
   [junit4] Suite: org.apache.solr.cloud.OverseerTest
   [junit4]   2> Creating dataDir: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\solr.cloud.OverseerTest-B9959006173984F3-001\init-core-data-001
   [junit4]   2> 2307736 T7534 oas.SolrTestCaseJ4.buildSSLConfig Randomized ssl (true) and clientAuth (false)
   [junit4]   2> 2307736 T7534 oas.SolrTestCaseJ4.initCore ####initCore
   [junit4]   2> 2307737 T7534 oas.SolrTestCaseJ4.initCore ####initCore end
   [junit4]   2> 2307742 T7534 oas.SolrTestCaseJ4.setUp ###Starting testOverseerFailure
   [junit4]   2> 2307745 T7534 oasc.ZkTestServer.run STARTING ZK TEST SERVER
   [junit4]   1> client port:0.0.0.0/0.0.0.0:0
   [junit4]   2> 2307747 T7535 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
   [junit4]   2> 2307845 T7534 oasc.ZkTestServer.run start zk server on port:56610
   [junit4]   2> 2307847 T7534 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 2307852 T7541 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1c67356 name:ZooKeeperConnection Watcher:127.0.0.1:56610 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 2307852 T7534 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 2307855 T7536 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x145b5d8d3400000, 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:744)
   [junit4]   2> 
   [junit4]   2> 2307856 T7534 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 2307859 T7543 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@196da81 name:ZooKeeperConnection Watcher:127.0.0.1:56610 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 2307860 T7534 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 2307860 T7534 oascc.SolrZkClient.makePath makePath: /solr
   [junit4]   2> 2307868 T7536 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x145b5d8d3400001, 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:744)
   [junit4]   2> 
   [junit4]   2> 2307869 T7534 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 2307873 T7545 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@19e28e4 name:ZooKeeperConnection Watcher:127.0.0.1:56610/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 2307874 T7534 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 2307874 T7534 oascc.SolrZkClient.makePath makePath: /live_nodes
   [junit4]   2> 2307878 T7534 oascc.SolrZkClient.makePath makePath: /clusterstate.json
   [junit4]   2> 2307881 T7534 oascc.SolrZkClient.makePath makePath: /aliases.json
   [junit4]   2> 2307884 T7534 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 2307899 T7534 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 2307901 T7547 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1e44df4 name:ZooKeeperConnection Watcher:127.0.0.1:56610/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 2307901 T7534 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 2307903 T7534 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 2307907 T7534 oascc.SolrZkClient.makePath makePath: /live_nodes/node1
   [junit4]   2> 2307913 T7534 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 2307915 T7549 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@167dad6 name:ZooKeeperConnection Watcher:127.0.0.1:56610/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 2307916 T7534 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 2307918 T7534 oascc.SolrZkClient.makePath makePath: /overseer_elect
   [junit4]   2> 2307921 T7534 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
   [junit4]   2> 2307928 T7534 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:56610_solr
   [junit4]   2> 2307929 T7534 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
   [junit4]   2> 2307936 T7534 oasc.Overseer.start Overseer (id=91679310292713476-127.0.0.1:56610_solr-n_0000000000) starting
   [junit4]   2> 2307940 T7534 oascc.SolrZkClient.makePath makePath: /overseer/queue
   [junit4]   2> 2307946 T7534 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
   [junit4]   2> 2307951 T7534 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-failure
   [junit4]   2> 2307957 T7534 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-running
   [junit4]   2> 2307962 T7534 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-completed
   [junit4]   2> 2307969 T7534 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
   [junit4]   2> 2307979 T7551 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
   [junit4]   2> 2307980 T7551 oasc.OverseerCollectionProcessor.prioritizeOverseerNodes prioritizing overseer nodes at 127.0.0.1:56610_solr
   [junit4]   2> 2307980 T7550 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
   [junit4]   2> 2308968 T7549 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2308971 T7550 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 2308972 T7550 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> 2308972 T7550 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1]
   [junit4]   2> 2308973 T7550 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
   [junit4]   2> 2308978 T7549 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2308980 T7545 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> 2308980 T7547 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> 2309460 T7534 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
   [junit4]   2> 2309478 T7534 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 2309486 T7549 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2309488 T7534 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 2309489 T7550 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 2309493 T7549 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2309493 T7534 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
   [junit4]   2> 2309497 T7550 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> 2309497 T7550 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
   [junit4]   2> 2309502 T7549 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2309593 T7547 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> 2309594 T7545 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> 2309644 T7536 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x145b5d8d3400004, 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:744)
   [junit4]   2> 
   [junit4]   2> 2310533 T7534 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
   [junit4]   2> 2310544 T7534 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 2310546 T7553 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@f94cc6 name:ZooKeeperConnection Watcher:127.0.0.1:56610/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 2310547 T7534 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 2310548 T7550 oasc.Overseer$ClusterStateUpdater.run Overseer Loop exiting : 127.0.0.1:56610_solr
   [junit4]   2> 2310551 T7554 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:306)
   [junit4]   2> 	at org.apache.solr.cloud.Overseer$ClusterStateUpdater.access$300(Overseer.java:85)
   [junit4]   2> 	at org.apache.solr.cloud.Overseer$ClusterStateUpdater$1.run(Overseer.java:289)
   [junit4]   2> 
   [junit4]   2> 2310556 T7534 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:56610_solr
   [junit4]   2> 2310557 T7534 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
   [junit4]   2> 2310560 T7534 oasc.Overseer.start Overseer (id=91679310292713477-127.0.0.1:56610_solr-n_0000000001) starting
   [junit4]   2> 2310584 T7556 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
   [junit4]   2> 2310585 T7556 oasc.OverseerCollectionProcessor.prioritizeOverseerNodes prioritizing overseer nodes at 127.0.0.1:56610_solr
   [junit4]   2> 2310586 T7555 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
   [junit4]   2> 2310588 T7555 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 2310589 T7555 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> 2310589 T7555 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
   [junit4]   2> 2310593 T7553 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2310594 T7547 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> 2310594 T7545 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> 2310644 T7553 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2310644 T7534 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
   [junit4]   2> 2310646 T7555 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 2310654 T7534 oasc.LeaderElector.checkIfIamLeader WARN Failed setting watch org.apache.zookeeper.KeeperException$NoNodeException: KeeperErrorCode = NoNode for /collections/collection1/leader_elect/shard1/election/91679310292713475-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 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:744)
   [junit4]   2> 
   [junit4]   2> 2310654 T7547 oasc.LeaderElector.checkIfIamLeader WARN Our node is no longer in line to be leader
   [junit4]   2> 2310657 T7555 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:1066)
   [junit4]   2> 		at org.apache.solr.cloud.Overseer$ClusterStateUpdater.processMessage(Overseer.java:346)
   [junit4]   2> 		at org.apache.solr.cloud.Overseer$ClusterStateUpdater.run(Overseer.java:242)
   [junit4]   2> 		at java.lang.Thread.run(Thread.java:744)
   [junit4]   2> 	
   [junit4]   2> 2310659 T7547 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 2310660 T7534 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 2310662 T7553 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2310669 T7553 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2310670 T7555 oasc.Overseer$ClusterStateUpdater.setShardLeader ERROR Could not mark shard leader for non existing collection:collection1
   [junit4]   2> 2310675 T7553 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2310767 T7547 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> 2310767 T7545 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> 2311552 T7534 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 2312442 T7534 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 2313333 T7534 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 2314223 T7534 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 2315115 T7534 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 2316007 T7534 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 2316897 T7534 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 2317788 T7534 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 2318653 T7534 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 2319454 T7534 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 2320256 T7534 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 2321057 T7534 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 2321859 T7534 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 2322660 T7534 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 2323462 T7534 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 2323471 T7536 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x145b5d8d3400003, 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:744)
   [junit4]   2> 
   [junit4]   2> 2323474 T7536 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x145b5d8d3400005, 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:744)
   [junit4]   2> 
   [junit4]   2> 2323475 T7534 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:56610 56610
   [junit4]   2> 2325272 T7535 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:56610 56610
   [junit4]   2> 2325274 T7534 oas.SolrTestCaseJ4.tearDown ###Ending testOverseerFailure
   [junit4]   2> 2325274 T7555 oasc.Overseer$ClusterStateUpdater.run Overseer Loop exiting : 127.0.0.1:56610_solr
   [junit4]   2> 2325277 T7557 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:306)
   [junit4]   2> 	at org.apache.solr.cloud.Overseer$ClusterStateUpdater.access$300(Overseer.java:85)
   [junit4]   2> 	at org.apache.solr.cloud.Overseer$ClusterStateUpdater$1.run(Overseer.java:289)
   [junit4]   2> 
   [junit4]   2> NOTE: reproduce with: ant test  -Dtestcase=OverseerTest -Dtests.method=testOverseerFailure -Dtests.seed=B9959006173984F3 -Dtests.slow=true -Dtests.locale=in -Dtests.timezone=Asia/Riyadh89 -Dtests.file.encoding=ISO-8859-1
   [junit4] ERROR   17.6s | 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([B9959006173984F3:BD9D1FF5059C6BD2]: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:744)
   [junit4]    > Caused by: org.apache.zookeeper.KeeperException$NodeExistsException: KeeperErrorCode = NodeExists for /collections/collection1/leaders/shard1
   [junit4]    > 	at org.apache.zookeeper.KeeperException.create(KeeperException.java:119)
   [junit4]    > 	at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
   [junit4]    > 	at org.apache.zookeeper.ZooKeeper.create(ZooKeeper.java:783)
   [junit4]    > 	at org.apache.solr.common.cloud.SolrZkClient$10.execute(SolrZkClient.java: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:31)
   [junit4]    > 	at org.apache.solr.cloud.ShardLeaderElectionContextBase.runLeaderProcess(ElectionContext.java:123)
   [junit4]    > 	... 47 more
   [junit4]   2> 2325305 T7534 oas.SolrTestCaseJ4.setUp ###Starting testBadQueueItem
   [junit4]   2> 2325306 T7534 oasc.ZkTestServer.run STARTING ZK TEST SERVER
   [junit4]   1> client port:0.0.0.0/0.0.0.0:0
   [junit4]   2> 2325308 T7558 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
   [junit4]   2> 2325387 T7534 oasc.ZkTestServer.run start zk server on port:56631
   [junit4]   2> 2325390 T7534 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 2325394 T7564 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@8d1d4d name:ZooKeeperConnection Watcher:127.0.0.1:56631 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 2325395 T7534 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 2325398 T7559 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x145b5d917d50000, 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:744)
   [junit4]   2> 
   [junit4]   2> 2325400 T7534 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 2325402 T7566 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@189b84b name:ZooKeeperConnection Watcher:127.0.0.1:56631 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 2325403 T7534 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 2325403 T7534 oascc.SolrZkClient.makePath makePath: /solr
   [junit4]   2> 2325409 T7559 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x145b5d917d50001, 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:744)
   [junit4]   2> 
   [junit4]   2> 2325411 T7534 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 2325414 T7568 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@a0cdcd name:ZooKeeperConnection Watcher:127.0.0.1:56631/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 2325414 T7534 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 2325415 T7534 oascc.SolrZkClient.makePath makePath: /live_nodes
   [junit4]   2> 2325419 T7534 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 2325422 T7570 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1c86990 name:ZooKeeperConnection Watcher:127.0.0.1:56631/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 2325422 T7534 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 2325423 T7534 oascc.SolrZkClient.makePath makePath: /overseer_elect
   [junit4]   2> 2325427 T7534 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
   [junit4]   2> 2325436 T7534 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:56631_solr
   [junit4]   2> 2325436 T7534 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
   [junit4]   2> 2325441 T7534 oasc.Overseer.start Overseer (id=91679311443329027-127.0.0.1:56631_solr-n_0000000000) starting
   [junit4]   2> 2325446 T7534 oascc.SolrZkClient.makePath makePath: /overseer/queue
   [junit4]   2> 2325451 T7534 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
   [junit4]   2> 2325456 T7534 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-failure
   [junit4]   2> 2325461 T7534 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-running
   [junit4]   2> 2325465 T7534 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-completed
   [junit4]   2> 2325474 T7534 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
   [junit4]   2> 2325485 T7572 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
   [junit4]   2> 2325486 T7534 oascc.SolrZkClient.makePath makePath: /clusterstate.json
   [junit4]   2> 2325487 T7572 oasc.OverseerCollectionProcessor.prioritizeOverseerNodes prioritizing overseer nodes at 127.0.0.1:56631_solr
   [junit4]   2> 2325489 T7571 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
   [junit4]   2> 2325492 T7534 oascc.SolrZkClient.makePath makePath: /aliases.json
   [junit4]   2> 2325494 T7534 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 2325500 T7534 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 2325503 T7574 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@e4070c name:ZooKeeperConnection Watcher:127.0.0.1:56631/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 2325503 T7534 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 2325505 T7534 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 2325509 T7534 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1
   [junit4]   2> 2325516 T7570 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2325519 T7571 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 2325520 T7571 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"active",
   [junit4]   2> 	  "node_name":"127.0.0.1",
   [junit4]   2> 	  "core":"core1",
   [junit4]   2> 	  "core_node_name":"node1",
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "numShards":"3",
   [junit4]   2> 	  "base_url":"http://127.0.0.1/solr/"}
   [junit4]   2> 2325520 T7571 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1, shard2, shard3]
   [junit4]   2> 2325520 T7571 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard3
   [junit4]   2> 2325524 T7570 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2325526 T7568 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> 2325527 T7574 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> 2325915 T7534 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard3/election
   [junit4]   2> 2325929 T7534 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard3
   [junit4]   2> 2325939 T7570 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2325941 T7570 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2325942 T7571 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 2325948 T7571 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"active",
   [junit4]   2> 	  "node_name":"127.0.0.1",
   [junit4]   2> 	  "core":"core2",
   [junit4]   2> 	  "core_node_name":"node2",
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "numShards":"3",
   [junit4]   2> 	  "base_url":"http://127.0.0.1/solr/"}
   [junit4]   2> 2325948 T7571 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
   [junit4]   2> 2325948 T7571 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard2
   [junit4]   2> 2325953 T7570 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2326037 T7568 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> 2326037 T7574 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> 2326337 T7534 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard2/election
   [junit4]   2> 2326347 T7534 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard2
   [junit4]   2> 2326354 T7570 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2326354 T7570 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2326355 T7570 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2326356 T7570 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2326357 T7571 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 2326363 T7571 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"active",
   [junit4]   2> 	  "node_name":"127.0.0.1",
   [junit4]   2> 	  "core":"core3",
   [junit4]   2> 	  "core_node_name":"node3",
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "numShards":"3",
   [junit4]   2> 	  "base_url":"http://127.0.0.1/solr/"}
   [junit4]   2> 2326363 T7571 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
   [junit4]   2> 2326363 T7571 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
   [junit4]   2> 2326367 T7570 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2326441 T7568 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> 2326442 T7574 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> 2326716 T7534 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
   [junit4]   2> 2326724 T7534 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 2326731 T7570 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2326731 T7570 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2326731 T7570 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2326733 T7571 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 2326736 T7570 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2326811 T7568 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> 2326812 T7574 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> 2326845 T7570 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2326845 T7570 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2326845 T7570 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2326850 T7570 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2326850 T7571 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 2326852 T7571 oasc.Overseer$ClusterStateUpdater.checkKeyExistence ERROR Skipping invalid Overseer message because it has no collection specified: {
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"active",
   [junit4]   2> 	  "node_name":"127.0.0.1",
   [junit4]   2> 	  "core":"core0",
   [junit4]   2> 	  "core_node_name":"node0",
   [junit4]   2> 	  "collection":"",
   [junit4]   2> 	  "numShards":"1",
   [junit4]   2> 	  "base_url":"http://127.0.0.1/solr/"}
   [junit4]   2> 2326862 T7571 oasc.Overseer$ClusterStateUpdater.checkKeyExistence ERROR Skipping invalid Overseer message because it has no collection specified: {
   [junit4]   2> 	  "operation":"deletecore",
   [junit4]   2> 	  "node_name":"127.0.0.1",
   [junit4]   2> 	  "core":"core0",
   [junit4]   2> 	  "core_node_name":"node0",
   [junit4]   2> 	  "collection":""}
   [junit4]   2> 2326869 T7570 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2326871 T7571 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"active",
   [junit4]   2> 	  "node_name":"127.0.0.1",
   [junit4]   2> 	  "core":"core1",
   [junit4]   2> 	  "core_node_name":"node1",
   [junit4]   2> 	  "collection":"collection2",
   [junit4]   2> 	  "numShards":"3",
   [junit4]   2> 	  "base_url":"http://127.0.0.1/solr/"}
   [junit4]   2> 2326871 T7571 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection2 with shards [shard1, shard2, shard3]
   [junit4]   2> 2326871 T7571 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard3
   [junit4]   2> 2326879 T7570 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2326954 T7574 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> 2326955 T7568 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> 2327215 T7534 oascc.SolrZkClient.makePath makePath: /collections/collection2/leader_elect/shard3/election
   [junit4]   2> 2327226 T7534 oascc.SolrZkClient.makePath makePath: /collections/collection2/leaders/shard3
   [junit4]   2> 2327234 T7570 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2327234 T7570 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2327234 T7570 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2327236 T7570 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2327237 T7571 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 2327243 T7571 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"active",
   [junit4]   2> 	  "node_name":"127.0.0.1",
   [junit4]   2> 	  "core":"core2",
   [junit4]   2> 	  "core_node_name":"node2",
   [junit4]   2> 	  "collection":"collection2",
   [junit4]   2> 	  "numShards":"3",
   [junit4]   2> 	  "base_url":"http://127.0.0.1/solr/"}
   [junit4]   2> 2327243 T7571 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
   [junit4]   2> 2327243 T7571 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard2
   [junit4]   2> 2327246 T7570 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2327321 T7568 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> 2327321 T7574 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> 2327595 T7534 oascc.SolrZkClient.makePath makePath: /collections/collection2/leader_elect/shard2/election
   [junit4]   2> 2327604 T7534 oascc.SolrZkClient.makePath makePath: /collections/collection2/leaders/shard2
   [junit4]   2> 2327609 T7570 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2327609 T7570 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2327609 T7570 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2327611 T7570 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2327612 T7571 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 2327617 T7571 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"active",
   [junit4]   2> 	  "node_name":"127.0.0.1",
   [junit4]   2> 	  "core":"core3",
   [junit4]   2> 	  "core_node_name":"node3",
   [junit4]   2> 	  "collection":"collection2",
   [junit4]   2> 	  "numShards":"3",
   [junit4]   2> 	  "base_url":"http://127.0.0.1/solr/"}
   [junit4]   2> 2327617 T7571 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
   [junit4]   2> 2327617 T7571 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
   [junit4]   2> 2327620 T7570 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2327695 T7568 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> 2327695 T7574 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> 2327970 T7534 oascc.SolrZkClient.makePath makePath: /collections/collection2/leader_elect/shard1/election
   [junit4]   2> 2327979 T7534 oascc.SolrZkClient.makePath makePath: /collections/collection2/leaders/shard1
   [junit4]   2> 2327985 T7570 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2327985 T7570 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2327985 T7570 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2327987 T7571 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 2327990 T7570 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2328065 T7568 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> 2328065 T7574 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> 2328097 T7559 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x145b5d917d50002, 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:744)
   [junit4]   2> 
   [junit4]   2> 2328100 T7559 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x145b5d917d50004, 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:744)
   [junit4]   2> 
   [junit4]   2> 2328102 T7534 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:56631 56631
   [junit4]   2> 2328102 T7559 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x145b5d917d50003, 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:744)
   [junit4]   2> 
   [junit4]   2> 2329725 T7558 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:56631 56631
   [junit4]   2> 2329727 T7534 oas.SolrTestCaseJ4.tearDown ###Ending testBadQueueItem
   [junit4]   2> 2329728 T7571 oasc.Overseer$ClusterStateUpdater.run Overseer Loop exiting : 127.0.0.1:56631_solr
   [junit4]   2> 2329730 T7575 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:306)
   [junit4]   2> 	at org.apache.solr.cloud.Overseer$ClusterStateUpdater.access$300(Overseer.java:85)
   [junit4]   2> 	at org.apache.solr.cloud.Overseer$ClusterStateUpdater$1.run(Overseer.java:289)
   [junit4]   2> 
   [junit4]   2> 2329736 T7534 oas.SolrTestCaseJ4.setUp ###Starting testShardLeaderChange
   [junit4]   2> 2329737 T7534 oasc.ZkTestServer.run STARTING ZK TEST SERVER
   [junit4]   1> client port:0.0.0.0/0.0.0.0:0
   [junit4]   2> 2329738 T7576 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
   [junit4]   2> 2329810 T7534 oasc.ZkTestServer.run start zk server on port:56649
   [junit4]   2> 2329812 T7534 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 2329816 T7582 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1aab31b name:ZooKeeperConnection Watcher:127.0.0.1:56649/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 2329816 T7534 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 2329818 T7534 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 2329819 T7584 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@12b0156 name:ZooKeeperConnection Watcher:127.0.0.1:56649 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 2329820 T7534 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 2329822 T7577 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x145b5d929240001, 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:744)
   [junit4]   2> 
   [junit4]   2> 2329823 T7534 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 2329826 T7586 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@b1d6b name:ZooKeeperConnection Watcher:127.0.0.1:56649 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 2329826 T7534 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 2329826 T7534 oascc.SolrZkClient.makePath makePath: /solr
   [junit4]   2> 2329831 T7534 oascc.SolrZkClient.makePath makePath: /live_nodes
   [junit4]   2> 2329831 T7577 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x145b5d929240002, 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:744)
   [junit4]   2> 
   [junit4]   2> 2329838 T7534 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 2329839 T7587 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 2329841 T7589 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@430858 name:ZooKeeperConnection Watcher:127.0.0.1:56649/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 2329841 T7534 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 2329842 T7591 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@d8ceab name:ZooKeeperConnection Watcher:127.0.0.1:56649/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 2329842 T7587 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 2329842 T7534 oascc.SolrZkClient.makePath makePath: /clusterstate.json
   [junit4]   2> 2329844 T7587 oascc.SolrZkClient.makePath makePath: /overseer_elect
   [junit4]   2> 2329847 T7534 oascc.SolrZkClient.makePath makePath: /aliases.json
   [junit4]   2> 2329848 T7587 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
   [junit4]   2> 2329851 T7534 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 2329875 T7587 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:56649_solr
   [junit4]   2> 2329875 T7534 oascc.SolrZkClient.makePath makePath: /live_nodes/node1
   [junit4]   2> 2329875 T7587 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
   [junit4]   2> 2329879 T7587 oasc.Overseer.start Overseer (id=91679311733719044-127.0.0.1:56649_solr-n_0000000000) starting
   [junit4]   2> 2329884 T7534 oascc.SolrZkClient.makePath makePath: /overseer/queue
   [junit4]   2> 2329884 T7587 oascc.SolrZkClient.makePath makePath: /overseer/queue
   [junit4]   2> 2329889 T7587 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
   [junit4]   2> 2329893 T7587 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-failure
   [junit4]   2> 2329898 T7587 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-running
   [junit4]   2> 2329902 T7587 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-completed
   [junit4]   2> 2329907 T7587 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
   [junit4]   2> 2329914 T7587 oasc.OverseerTest$OverseerRestarter.run Killing overseer.
   [junit4]   2> 2329915 T7593 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
   [junit4]   2> 2329917 T7587 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 2329919 T7595 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@6a2ec7 name:ZooKeeperConnection Watcher:127.0.0.1:56649/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 2329919 T7587 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 2329919 T7593 oasc.OverseerCollectionProcessor.amILeader According to ZK I (id=91679311733719044-127.0.0.1:56649_solr-n_0000000000) am no longer a leader.
   [junit4]   2> 2329919 T7593 oasc.OverseerCollectionProcessor.prioritizeOverseerNodes prioritizing overseer nodes at 127.0.0.1:56649_solr
   [junit4]   2> 2329921 T7593 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:293)
   [junit4]   2> 	at org.apache.solr.cloud.OverseerCollectionProcessor.run(OverseerCollectionProcessor.java:206)
   [junit4]   2> 	at java.lang.Thread.run(Thread.java:744)
   [junit4]   2> 
   [junit4]   2> 2329924 T7587 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:56649_solr
   [junit4]   2> 2329924 T7587 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
   [junit4]   2> 2329926 T7587 oasc.Overseer.start Overseer (id=91679311733719045-127.0.0.1:56649_solr-n_0000000001) starting
   [junit4]   2> 2329941 T7597 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
   [junit4]   2> 2329943 T7597 oasc.OverseerCollectionProcessor.prioritizeOverseerNodes prioritizing overseer nodes at 127.0.0.1:56649_solr
   [junit4]   2> 2329943 T7596 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
   [junit4]   2> 2329946 T7596 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 2329947 T7596 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> 2329947 T7596 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1]
   [junit4]   2> 2329947 T7596 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
   [junit4]   2> 2329951 T7595 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2329952 T7589 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> 2330247 T7534 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
   [junit4]   2> 2330272 T7534 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 2330280 T7595 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2330283 T7534 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
   [junit4]   2> 2330283 T7596 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 2330283 T7595 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2330289 T7596 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> 2330289 T7596 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
   [junit4]   2> 2330293 T7595 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2330294 T7534 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 2330296 T7599 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1b4e7b1 name:ZooKeeperConnection Watcher:127.0.0.1:56649/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 2330296 T7534 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 2330298 T7534 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 2330301 T7534 oascc.SolrZkClient.makePath makePath: /live_nodes/node2
   [junit4]   2> 2330306 T7534 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
   [junit4]   2> 2330306 T7595 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2330308 T7596 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> 2330308 T7596 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
   [junit4]   2> 2330313 T7595 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2330315 T7534 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 2330390 T7599 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> 2330390 T7589 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> 2330460 T7534 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 2330469 T7595 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2330469 T7595 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2330469 T7595 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2330473 T7596 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 2330474 T7596 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> 2330474 T7596 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=1
   [junit4]   2> 2330474 T7596 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
   [junit4]   2> 2330480 T7595 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2330556 T7589 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> 2330556 T7599 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> 2330828 T7534 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
   [junit4]   2> 2330837 T7577 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x145b5d929240003, 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:744)
   [junit4]   2> 
   [junit4]   2> 2330837 T7534 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 2330839 T7599 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 2330844 T7595 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2330844 T7595 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2330844 T7595 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2330846 T7596 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 2330851 T7595 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2330926 T7599 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> 2330982 T7534 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 2330984 T7534 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 2330987 T7601 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@6f70ea name:ZooKeeperConnection Watcher:127.0.0.1:56649/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 2330987 T7534 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 2330989 T7534 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 2330991 T7534 oascc.SolrZkClient.makePath makePath: /live_nodes/node1
   [junit4]   2> 2330997 T7534 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
   [junit4]   2> 2330998 T7595 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2330998 T7595 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2330999 T7595 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2331000 T7596 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 2331001 T7596 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> 2331002 T7596 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
   [junit4]   2> 2331008 T7595 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2331009 T7577 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x145b5d929240006, 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:744)
   [junit4]   2> 
   [junit4]   2> 2331012 T7601 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 2331013 T7534 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
   [junit4]   2> 2331013 T7595 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2331015 T7596 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> 2331016 T7596 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
   [junit4]   2> 2331022 T7595 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2331024 T7587 oasc.OverseerTest$OverseerRestarter.run Killing overseer.
   [junit4]   2> 2331026 T7534 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 2331027 T7596 oasc.Overseer$ClusterStateUpdater.run WARN Solr cannot talk to ZK, exiting Overseer main queue loop org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /overseer/queue
   [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.DistributedQueue.orderedChildren(DistributedQueue.java:96)
   [junit4]   2> 	at org.apache.solr.cloud.DistributedQueue.remove(DistributedQueue.java:169)
   [junit4]   2> 	at org.apache.solr.cloud.DistributedQueue.poll(DistributedQueue.java:493)
   [junit4]   2> 	at org.apache.solr.cloud.Overseer$ClusterStateUpdater.run(Overseer.java:257)
   [junit4]   2> 	at java.lang.Thread.run(Thread.java:744)
   [junit4]   2> 
   [junit4]   2> 2331028 T7596 oasc.Overseer$ClusterStateUpdater.run Overseer Loop exiting : 127.0.0.1:56649_solr
   [junit4]   2> 2331029 T7587 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 2331031 T7606 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:306)
   [junit4]   2> 	at org.apache.solr.cloud.Overseer$ClusterStateUpdater.access$300(Overseer.java:85)
   [junit4]   2> 	at org.apache.solr.cloud.Overseer$ClusterStateUpdater$1.run(Overseer.java:289)
   [junit4]   2> 
   [junit4]   2> 2331032 T7605 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@7ab6f4 name:ZooKeeperConnection Watcher:127.0.0.1:56649/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 2331033 T7587 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 2331034 T7603 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@b75bcd name:ZooKeeperConnection Watcher:127.0.0.1:56649/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 2331034 T7534 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 2331036 T7534 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 2331039 T7587 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:56649_solr
   [junit4]   2> 2331039 T7587 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
   [junit4]   2> 2331041 T7534 oascc.SolrZkClient.makePath makePath: /live_nodes/node2
   [junit4]   2> 2331044 T7587 oasc.Overseer.start Overseer (id=91679311733719048-127.0.0.1:56649_solr-n_0000000002) starting
   [junit4]   2> 2331048 T7534 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
   [junit4]   2> 2331059 T7534 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 2331064 T7608 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
   [junit4]   2> 2331064 T7608 oasc.OverseerCollectionProcessor.prioritizeOverseerNodes prioritizing overseer nodes at 127.0.0.1:56649_solr
   [junit4]   2> 2331065 T7607 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 2331066 T7607 oasc.Overseer$ClusterStateUpdater.run Replaying operations from work queue.
   [junit4]   2> 2331067 T7607 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
   [j

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

apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /collections
   [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$3.execute(SolrZkClient.java:209)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient$3.execute(SolrZkClient.java:206)
   [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:206)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:417)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:386)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:373)
   [junit4]   2> 	at org.apache.solr.cloud.ShardLeaderElectionContextBase$1.execute(ElectionContext.java:128)
   [junit4]   2> 	at org.apache.solr.common.util.RetryUtil.retryOnThrowable(RetryUtil.java:31)
   [junit4]   2> 	at org.apache.solr.cloud.ShardLeaderElectionContextBase.runLeaderProcess(ElectionContext.java:123)
   [junit4]   2> 	... 6 more
   [junit4]   2> 
   [junit4]   2> 2351966 T7887 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
   [junit4]   2> 2351963 T7534 oas.SolrTestCaseJ4.tearDown ###Ending testShardAssignmentBigger
   [junit4]   2> 2351967 T7738 oasc.Overseer$ClusterStateUpdater.run Overseer Loop exiting : 127.0.0.1:56796_solr
   [junit4]   2> 2351968 T7534 oas.SolrTestCaseJ4.initCore ####initCore
   [junit4]   2> 2351969 T7974 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:306)
   [junit4]   2> 	at org.apache.solr.cloud.Overseer$ClusterStateUpdater.access$300(Overseer.java:85)
   [junit4]   2> 	at org.apache.solr.cloud.Overseer$ClusterStateUpdater$1.run(Overseer.java:289)
   [junit4]   2> 
   [junit4]   2> 2351969 T7534 oas.SolrTestCaseJ4.initCore ####initCore end
   [junit4]   2> 2354061 T7534 oas.SolrTestCaseJ4.deleteCore ###deleteCore
   [junit4]   2> NOTE: leaving temporary files on disk at: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\solr.cloud.OverseerTest-B9959006173984F3-001
   [junit4]   2> NOTE: test params are: codec=DummyCompressingStoredFields(storedFieldsFormat=CompressingStoredFieldsFormat(compressionMode=DUMMY, chunkSize=285), termVectorsFormat=CompressingTermVectorsFormat(compressionMode=DUMMY, chunkSize=285)), sim=RandomSimilarityProvider(queryNorm=false,coord=no): {}, locale=in, timezone=Asia/Riyadh89
   [junit4]   2> NOTE: Windows 7 6.1 x86/Oracle Corporation 1.7.0_60-ea (32-bit)/cpus=2,threads=1,free=118221064,total=367685632
   [junit4]   2> NOTE: All tests run in this JVM: [LegacyHTMLStripCharFilterTest, TestCloudInspectUtil, HighlighterConfigTest, XsltUpdateRequestHandlerTest, TestRequestStatusCollectionAPI, TestWriterPerf, OverseerStatusTest, TestUpdate, TestExtendedDismaxParser, TestMultiCoreConfBootstrap, TestCollationField, TestReplicationHandler, SolrTestCaseJ4Test, TestSchemaVersionResource, TestCollectionAPI, FastVectorHighlighterTest, DistributedExpandComponentTest, DocValuesMultiTest, TestZkChroot, ZkSolrClientTest, TestSimpleQParserPlugin, SearchHandlerTest, SoftAutoCommitTest, RegexBoostProcessorTest, TestStressUserVersions, AutoCommitTest, TestSolrXmlPersistence, TestInfoStreamLogging, CSVRequestHandlerTest, PeerSyncTest, TestComponentsName, ConnectionManagerTest, SolrCmdDistributorTest, DeleteInactiveReplicaTest, TermsComponentTest, TestBinaryResponseWriter, TestRealTimeGet, TestHighlightDedupGrouping, AnalysisAfterCoreReloadTest, SliceStateTest, CursorMarkTest, TestFoldingMultitermQuery, TestRandomDVFaceting, BadComponentTest, TestFreeTextSuggestions, TestCSVLoader, TestPHPSerializedResponseWriter, TestSchemaNameResource, CollectionsAPIAsyncDistributedZkTest, TestMaxScoreQueryParser, SuggesterWFSTTest, TestSuggestSpellingConverter, TestStressLucene, HdfsSyncSliceTest, HdfsRecoveryZkTest, ScriptEngineTest, IndexBasedSpellCheckerTest, TestHashPartitioner, TestValueSourceCache, AbstractAnalyticsFacetTest, TestExpandComponent, HdfsChaosMonkeySafeLeaderTest, TestReload, AddSchemaFieldsUpdateProcessorFactoryTest, OpenCloseCoreStressTest, TestSolrQueryParserResource, TestSolrJ, AbstractAnalyticsStatsTest, TestLRUCache, BlockCacheTest, TestBM25SimilarityFactory, AddBlockUpdateTest, SimpleFacetsTest, ShardRoutingTest, TestSort, HdfsCollectionsAPIDistributedZkTest, TestFieldSortValues, TestRecoveryHdfs, TestElisionMultitermQuery, SolrCoreTest, TestSolrXMLSerializer, BinaryUpdateRequestHandlerTest, DirectSolrSpellCheckerTest, MoreLikeThisHandlerTest, CursorPagingTest, SolrIndexSplitterTest, TestStandardQParsers, DistributedQueryComponentCustomSortTest, TestLuceneMatchVersion, HdfsUnloadDistributedZkTest, TestSolr4Spatial, CoreAdminHandlerTest, TestCursorMarkWithoutUniqueKey, TestQueryTypes, SSLMigrationTest, BasicDistributedZkTest, OutputWriterTest, TestFiltering, TestLazyCores, RecoveryZkTest, TestSolrIndexConfig, SignatureUpdateProcessorFactoryTest, SolrPluginUtilsTest, TimeZoneUtilsTest, NoCacheHeaderTest, DistanceFunctionTest, TestQueryUtils, TestRecovery, HdfsBasicDistributedZkTest, StatelessScriptUpdateProcessorFactoryTest, HdfsLockFactoryTest, SyncSliceTest, DocValuesMissingTest, TestPhraseSuggestions, SortByFunctionTest, DirectSolrConnectionTest, RangeFacetTest, HdfsBasicDistributedZk2Test, SpellCheckComponentTest, TestSurroundQueryParser, TestBadConfig, TestSolrDeletionPolicy2, JSONWriterTest, TestSolrDeletionPolicy1, SuggesterTSTTest, TestDefaultSearchFieldResource, TriLevelCompositeIdRoutingTest, DistributedSpellCheckComponentTest, TestMergePolicyConfig, TestDFRSimilarityFactory, ChangedSchemaMergeTest, TestSolrXmlPersistor, SpellPossibilityIteratorTest, HardAutoCommitTest, MultiTermTest, UpdateRequestProcessorFactoryTest, DisMaxRequestHandlerTest, SolrIndexConfigTest, RAMDirectoryFactoryTest, TestDistributedGrouping, TestManagedResource, DistributedSuggestComponentTest, WordBreakSolrSpellCheckerTest, TestNonNRTOpen, TestIndexingPerformance, TestLMJelinekMercerSimilarityFactory, DateFieldTest, CurrencyFieldOpenExchangeTest, TestManagedSchemaFieldResource, AsyncMigrateRouteKeyTest, CachingDirectoryFactoryTest, DistributedTermsComponentTest, TestRandomFaceting, TestFileDictionaryLookup, DistributedQueryElevationComponentTest, BasicDistributedZk2Test, TestSchemaSimilarityResource, QueryParsingTest, TestCSVResponseWriter, TestCopyFieldCollectionResource, DirectUpdateHandlerOptimizeTest, DocValuesTest, TestSolrCoreProperties, TestCoreContainer, TestSystemIdResolver, TestSweetSpotSimilarityFactory, TestFaceting, TestSolrQueryParser, SliceStateUpdateTest, TestCollationFieldDocValues, TestJmxIntegration, RequiredFieldsTest, TestNRTOpen, TestAnalyzedSuggestions, ChaosMonkeyNothingIsSafeTest, TestPartialUpdateDeduplication, TestStressRecovery, DistributedQueryComponentOptimizationTest, TestPseudoReturnFields, TestRandomMergePolicy, SystemInfoHandlerTest, CollectionsAPIDistributedZkTest, AssignTest, TestRTGBase, TestFunctionQuery, TestUtils, ChaosMonkeySafeLeaderTest, PreAnalyzedFieldTest, CurrencyFieldXmlFileTest, ZkNodePropsTest, DirectUpdateHandlerTest, SynonymTokenizerTest, ModifyConfFileTest, UnloadDistributedZkTest, OverseerTest]
   [junit4] Completed in 46.37s, 9 tests, 1 error <<< FAILURES!

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

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



Mime
View raw message