lucene-dev mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From Policeman Jenkins Server <jenk...@thetaphi.de>
Subject [JENKINS] Lucene-Solr-trunk-Linux (32bit/jdk1.7.0_55) - Build # 10200 - Failure!
Date Wed, 30 Apr 2014 22:37:04 GMT
Build: http://jenkins.thetaphi.de/job/Lucene-Solr-trunk-Linux/10200/
Java: 32bit/jdk1.7.0_55 -client -XX:+UseParallelGC

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

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

Stack Trace:
org.apache.solr.common.SolrException: Could not register as the leader because creating the ephemeral registration node in ZooKeeper failed
	at __randomizedtesting.SeedInfo.seed([1BF320DFA26F524F:1FFBAF2CB0CABD6E]: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:745)
Caused by: org.apache.zookeeper.KeeperException$NodeExistsException: KeeperErrorCode = NodeExists for /collections/collection1/leaders/shard1
	at org.apache.zookeeper.KeeperException.create(KeeperException.java:119)
	at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
	at org.apache.zookeeper.ZooKeeper.create(ZooKeeper.java:783)
	at org.apache.solr.common.cloud.SolrZkClient$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 11054 lines...]
   [junit4] Suite: org.apache.solr.cloud.OverseerTest
   [junit4]   2> Creating dataDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./solr.cloud.OverseerTest-1BF320DFA26F524F-001/init-core-data-001
   [junit4]   2> 451440 T1484 oas.SolrTestCaseJ4.buildSSLConfig Randomized ssl (true) and clientAuth (false)
   [junit4]   2> 451441 T1484 oas.SolrTestCaseJ4.initCore ####initCore
   [junit4]   2> 451441 T1484 oas.SolrTestCaseJ4.initCore ####initCore end
   [junit4]   2> 451444 T1484 oas.SolrTestCaseJ4.setUp ###Starting testDoubleAssignment
   [junit4]   2> 451444 T1484 oasc.ZkTestServer.run STARTING ZK TEST SERVER
   [junit4]   1> client port:0.0.0.0/0.0.0.0:0
   [junit4]   2> 451445 T1485 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
   [junit4]   2> 451545 T1484 oasc.ZkTestServer.run start zk server on port:49248
   [junit4]   2> 451546 T1484 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 451636 T1491 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@43fe20 name:ZooKeeperConnection Watcher:127.0.0.1:49248/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 451636 T1484 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 451638 T1484 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 451640 T1493 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@60c080 name:ZooKeeperConnection Watcher:127.0.0.1:49248 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 451641 T1484 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 451645 T1484 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 451646 T1495 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@7ea98b name:ZooKeeperConnection Watcher:127.0.0.1:49248 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 451647 T1484 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 451648 T1484 oascc.SolrZkClient.makePath makePath: /solr
   [junit4]   2> 451651 T1484 oascc.SolrZkClient.makePath makePath: /live_nodes
   [junit4]   2> 451655 T1484 oascc.SolrZkClient.makePath makePath: /clusterstate.json
   [junit4]   2> 451657 T1484 oascc.SolrZkClient.makePath makePath: /aliases.json
   [junit4]   2> 451660 T1484 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 451665 T1484 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 451667 T1497 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@14e7f9c name:ZooKeeperConnection Watcher:127.0.0.1:49248/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 451667 T1484 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 451670 T1484 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 451674 T1484 oascc.SolrZkClient.makePath makePath: /live_nodes/node1
   [junit4]   2> 451679 T1484 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 451681 T1499 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@3098f2 name:ZooKeeperConnection Watcher:127.0.0.1:49248/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 451681 T1484 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 451683 T1484 oascc.SolrZkClient.makePath makePath: /overseer_elect
   [junit4]   2> 451687 T1484 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
   [junit4]   2> 451695 T1484 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:49248_solr
   [junit4]   2> 451696 T1484 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
   [junit4]   2> 451699 T1484 oasc.Overseer.start Overseer (id=91678076890644484-127.0.0.1:49248_solr-n_0000000000) starting
   [junit4]   2> 451702 T1484 oascc.SolrZkClient.makePath makePath: /overseer/queue
   [junit4]   2> 451708 T1484 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
   [junit4]   2> 451712 T1484 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-failure
   [junit4]   2> 451716 T1484 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-running
   [junit4]   2> 451722 T1484 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-completed
   [junit4]   2> 451728 T1484 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
   [junit4]   2> 451736 T1501 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
   [junit4]   2> 451737 T1501 oasc.OverseerCollectionProcessor.prioritizeOverseerNodes prioritizing overseer nodes at 127.0.0.1:49248_solr
   [junit4]   2> 451737 T1500 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
   [junit4]   2> 451740 T1500 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 451741 T1500 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> 451741 T1500 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1]
   [junit4]   2> 451742 T1500 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
   [junit4]   2> 451745 T1499 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 451746 T1491 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> 451747 T1497 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> 452238 T1484 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
   [junit4]   2> 452346 T1484 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 452353 T1499 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 452353 T1484 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 452354 T1500 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 452359 T1484 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 452360 T1499 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 452361 T1503 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@37cecb name:ZooKeeperConnection Watcher:127.0.0.1:49248/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 452361 T1484 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 452363 T1484 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 452367 T1484 oascc.SolrZkClient.makePath makePath: /live_nodes/node1
   [junit4]   2> 452372 T1484 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
   [junit4]   2> 452372 T1499 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 452375 T1500 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> 452375 T1500 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
   [junit4]   2> 452379 T1499 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 452380 T1484 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 452386 T1499 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 452391 T1499 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 452494 T1491 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> 452494 T1503 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> 452495 T1484 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 452502 T1484 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:49248 49248
   [junit4]   2> 452609 T1485 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:49248 49248
   [junit4]   2> 452610 T1484 oas.SolrTestCaseJ4.tearDown ###Ending testDoubleAssignment
   [junit4]   2> 452610 T1500 oasc.Overseer$ClusterStateUpdater.run Overseer Loop exiting : 127.0.0.1:49248_solr
   [junit4]   2> 452612 T1504 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> 452615 T1484 oas.SolrTestCaseJ4.setUp ###Starting testOverseerFailure
   [junit4]   2> 452616 T1484 oasc.ZkTestServer.run STARTING ZK TEST SERVER
   [junit4]   1> client port:0.0.0.0/0.0.0.0:0
   [junit4]   2> 452616 T1505 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
   [junit4]   2> 452716 T1484 oasc.ZkTestServer.run start zk server on port:40229
   [junit4]   2> 452717 T1484 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 452720 T1511 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@c5602c name:ZooKeeperConnection Watcher:127.0.0.1:40229 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 452720 T1484 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 452722 T1484 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 452723 T1513 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1d62d38 name:ZooKeeperConnection Watcher:127.0.0.1:40229 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 452724 T1484 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 452724 T1484 oascc.SolrZkClient.makePath makePath: /solr
   [junit4]   2> 452727 T1484 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 452728 T1515 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@8e13a1 name:ZooKeeperConnection Watcher:127.0.0.1:40229/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 452728 T1484 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 452728 T1484 oascc.SolrZkClient.makePath makePath: /live_nodes
   [junit4]   2> 452730 T1484 oascc.SolrZkClient.makePath makePath: /clusterstate.json
   [junit4]   2> 452732 T1484 oascc.SolrZkClient.makePath makePath: /aliases.json
   [junit4]   2> 452733 T1484 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 452735 T1484 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 452736 T1517 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@2e609f name:ZooKeeperConnection Watcher:127.0.0.1:40229/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 452736 T1484 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 452737 T1484 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 452738 T1484 oascc.SolrZkClient.makePath makePath: /live_nodes/node1
   [junit4]   2> 452741 T1484 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 452742 T1519 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@35ab0c name:ZooKeeperConnection Watcher:127.0.0.1:40229/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 452742 T1484 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 452743 T1484 oascc.SolrZkClient.makePath makePath: /overseer_elect
   [junit4]   2> 452745 T1484 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
   [junit4]   2> 452749 T1484 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:40229_solr
   [junit4]   2> 452749 T1484 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
   [junit4]   2> 452751 T1484 oasc.Overseer.start Overseer (id=91678076967321604-127.0.0.1:40229_solr-n_0000000000) starting
   [junit4]   2> 452753 T1484 oascc.SolrZkClient.makePath makePath: /overseer/queue
   [junit4]   2> 452755 T1484 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
   [junit4]   2> 452756 T1484 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-failure
   [junit4]   2> 452758 T1484 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-running
   [junit4]   2> 452760 T1484 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-completed
   [junit4]   2> 452763 T1484 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
   [junit4]   2> 452766 T1521 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
   [junit4]   2> 452767 T1521 oasc.OverseerCollectionProcessor.prioritizeOverseerNodes prioritizing overseer nodes at 127.0.0.1:40229_solr
   [junit4]   2> 452767 T1520 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
   [junit4]   2> 453770 T1519 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 453773 T1520 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 453774 T1520 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> 453775 T1520 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1]
   [junit4]   2> 453775 T1520 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
   [junit4]   2> 453778 T1519 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 453779 T1517 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> 453779 T1515 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> 454271 T1484 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
   [junit4]   2> 454285 T1484 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 454292 T1519 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 454292 T1484 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 454294 T1520 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 454296 T1519 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 454296 T1484 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
   [junit4]   2> 454299 T1520 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> 454300 T1520 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
   [junit4]   2> 454302 T1519 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 454406 T1515 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> 454406 T1517 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> 455460 T1484 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
   [junit4]   2> 455464 T1484 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 455466 T1523 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1efeef0 name:ZooKeeperConnection Watcher:127.0.0.1:40229/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 455466 T1484 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 455466 T1520 oasc.Overseer$ClusterStateUpdater.run Overseer Loop exiting : 127.0.0.1:40229_solr
   [junit4]   2> 455467 T1524 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> 455469 T1484 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:40229_solr
   [junit4]   2> 455469 T1484 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
   [junit4]   2> 455471 T1484 oasc.Overseer.start Overseer (id=91678076967321605-127.0.0.1:40229_solr-n_0000000001) starting
   [junit4]   2> 455480 T1526 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
   [junit4]   2> 455480 T1525 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
   [junit4]   2> 455481 T1526 oasc.OverseerCollectionProcessor.prioritizeOverseerNodes prioritizing overseer nodes at 127.0.0.1:40229_solr
   [junit4]   2> 455482 T1525 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 455482 T1525 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> 455482 T1525 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
   [junit4]   2> 455484 T1523 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 455484 T1515 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> 455484 T1517 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> 455537 T1523 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 455537 T1484 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
   [junit4]   2> 455538 T1525 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 455541 T1484 oasc.LeaderElector.checkIfIamLeader WARN Failed setting watch org.apache.zookeeper.KeeperException$NoNodeException: KeeperErrorCode = NoNode for /collections/collection1/leader_elect/shard1/election/91678076967321603-node1_core1-n_0000000002
   [junit4]   2> 	at org.apache.zookeeper.KeeperException.create(KeeperException.java:111)
   [junit4]   2> 	at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
   [junit4]   2> 	at org.apache.zookeeper.ZooKeeper.getData(ZooKeeper.java:1155)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient$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:745)
   [junit4]   2> 
   [junit4]   2> 455543 T1525 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:745)
   [junit4]   2> 	
   [junit4]   2> 455542 T1517 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 455543 T1484 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 455550 T1523 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 455556 T1523 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 455558 T1517 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 455558 T1525 oasc.Overseer$ClusterStateUpdater.setShardLeader ERROR Could not mark shard leader for non existing collection:collection1
   [junit4]   2> 455561 T1523 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 455562 T1523 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 455563 T1525 oasc.Overseer$ClusterStateUpdater.setShardLeader ERROR Could not mark shard leader for non existing collection:collection1
   [junit4]   2> 455564 T1523 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 455667 T1517 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> 455667 T1515 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> 456551 T1484 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 457556 T1484 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 458560 T1484 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 459563 T1484 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 460566 T1484 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 461571 T1484 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 462577 T1484 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 463581 T1484 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 464583 T1484 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 465588 T1484 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 466591 T1484 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 467594 T1484 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 468599 T1484 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 469602 T1484 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 470605 T1484 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 470615 T1484 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:40229 40229
   [junit4]   2> 470681 T1505 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:40229 40229
   [junit4]   2> 470683 T1484 oas.SolrTestCaseJ4.tearDown ###Ending testOverseerFailure
   [junit4]   2> 470684 T1525 oasc.Overseer$ClusterStateUpdater.run Overseer Loop exiting : 127.0.0.1:40229_solr
   [junit4]   2> 470686 T1527 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=1BF320DFA26F524F -Dtests.multiplier=3 -Dtests.slow=true -Dtests.locale=vi_VN -Dtests.timezone=Africa/Juba -Dtests.file.encoding=US-ASCII
   [junit4] ERROR   18.1s J0 | OverseerTest.testOverseerFailure <<<
   [junit4]    > Throwable #1: org.apache.solr.common.SolrException: Could not register as the leader because creating the ephemeral registration node in ZooKeeper failed
   [junit4]    > 	at __randomizedtesting.SeedInfo.seed([1BF320DFA26F524F:1FFBAF2CB0CABD6E]:0)
   [junit4]    > 	at org.apache.solr.cloud.ShardLeaderElectionContextBase.runLeaderProcess(ElectionContext.java:136)
   [junit4]    > 	at org.apache.solr.cloud.LeaderElector.runIamLeaderProcess(LeaderElector.java:142)
   [junit4]    > 	at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:110)
   [junit4]    > 	at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:134)
   [junit4]    > 	at org.apache.solr.cloud.LeaderElector.joinElection(LeaderElector.java:267)
   [junit4]    > 	at org.apache.solr.cloud.OverseerTest$MockZKController.publishState(OverseerTest.java:155)
   [junit4]    > 	at org.apache.solr.cloud.OverseerTest.testOverseerFailure(OverseerTest.java:661)
   [junit4]    > 	at java.lang.Thread.run(Thread.java:745)
   [junit4]    > Caused by: org.apache.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> 470711 T1484 oas.SolrTestCaseJ4.setUp ###Starting testBadQueueItem
   [junit4]   2> 470713 T1484 oasc.ZkTestServer.run STARTING ZK TEST SERVER
   [junit4]   1> client port:0.0.0.0/0.0.0.0:0
   [junit4]   2> 470714 T1528 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
   [junit4]   2> 470814 T1484 oasc.ZkTestServer.run start zk server on port:58216
   [junit4]   2> 470815 T1484 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 470821 T1534 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1395668 name:ZooKeeperConnection Watcher:127.0.0.1:58216 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 470821 T1484 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 470823 T1484 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 470824 T1536 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@14558c6 name:ZooKeeperConnection Watcher:127.0.0.1:58216 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 470825 T1484 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 470825 T1484 oascc.SolrZkClient.makePath makePath: /solr
   [junit4]   2> 470828 T1484 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 470829 T1538 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@61631 name:ZooKeeperConnection Watcher:127.0.0.1:58216/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 470829 T1484 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 470829 T1484 oascc.SolrZkClient.makePath makePath: /live_nodes
   [junit4]   2> 470831 T1484 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 470832 T1540 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@54414d name:ZooKeeperConnection Watcher:127.0.0.1:58216/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 470832 T1484 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 470833 T1484 oascc.SolrZkClient.makePath makePath: /overseer_elect
   [junit4]   2> 470836 T1484 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
   [junit4]   2> 470839 T1484 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:58216_solr
   [junit4]   2> 470839 T1484 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
   [junit4]   2> 470841 T1484 oasc.Overseer.start Overseer (id=91678078153457667-127.0.0.1:58216_solr-n_0000000000) starting
   [junit4]   2> 470843 T1484 oascc.SolrZkClient.makePath makePath: /overseer/queue
   [junit4]   2> 470845 T1484 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
   [junit4]   2> 470848 T1484 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-failure
   [junit4]   2> 470851 T1484 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-running
   [junit4]   2> 470854 T1484 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-completed
   [junit4]   2> 470859 T1484 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
   [junit4]   2> 470864 T1542 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
   [junit4]   2> 470864 T1484 oascc.SolrZkClient.makePath makePath: /clusterstate.json
   [junit4]   2> 470864 T1541 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
   [junit4]   2> 470864 T1542 oasc.OverseerCollectionProcessor.prioritizeOverseerNodes prioritizing overseer nodes at 127.0.0.1:58216_solr
   [junit4]   2> 470867 T1484 oascc.SolrZkClient.makePath makePath: /aliases.json
   [junit4]   2> 470868 T1484 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 470872 T1484 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 470873 T1544 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@cdb2d2 name:ZooKeeperConnection Watcher:127.0.0.1:58216/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 470874 T1484 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 470875 T1484 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 470878 T1484 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1
   [junit4]   2> 470882 T1540 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 470883 T1541 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 470883 T1541 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> 470883 T1541 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1, shard2, shard3]
   [junit4]   2> 470884 T1541 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
   [junit4]   2> 470885 T1540 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 470886 T1538 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> 470886 T1544 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> 471382 T1484 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
   [junit4]   2> 471391 T1484 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 471394 T1540 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 471395 T1540 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 471395 T1541 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 471397 T1541 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> 471397 T1541 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
   [junit4]   2> 471397 T1541 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard3
   [junit4]   2> 471399 T1540 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 471501 T1538 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> 471501 T1544 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> 471895 T1484 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard3/election
   [junit4]   2> 471908 T1484 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard3
   [junit4]   2> 471915 T1540 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 471915 T1540 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 471916 T1540 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 471918 T1540 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 471919 T1541 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 471923 T1541 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> 471924 T1541 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
   [junit4]   2> 471924 T1541 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard2
   [junit4]   2> 471927 T1540 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 472030 T1538 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> 472030 T1544 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> 472418 T1484 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard2/election
   [junit4]   2> 472423 T1484 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard2
   [junit4]   2> 472429 T1540 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 472429 T1540 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 472429 T1540 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 472430 T1541 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 472432 T1540 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 472534 T1544 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> 472534 T1538 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> 472581 T1540 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 472581 T1540 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 472582 T1540 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 472583 T1541 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 472583 T1540 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 472583 T1541 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> 472585 T1541 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> 472586 T1540 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 472587 T1541 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> 472587 T1541 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection2 with shards [shard1, shard2, shard3]
   [junit4]   2> 472587 T1541 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
   [junit4]   2> 472589 T1540 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 472695 T1538 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> 472695 T1544 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> 473083 T1484 oascc.SolrZkClient.makePath makePath: /collections/collection2/leader_elect/shard1/election
   [junit4]   2> 473098 T1484 oascc.SolrZkClient.makePath makePath: /collections/collection2/leaders/shard1
   [junit4]   2> 473106 T1540 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 473106 T1540 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 473107 T1540 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 473108 T1541 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 473108 T1540 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 473114 T1541 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> 473114 T1541 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
   [junit4]   2> 473115 T1541 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard3
   [junit4]   2> 473118 T1540 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 473221 T1538 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> 473221 T1544 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> 473608 T1484 oascc.SolrZkClient.makePath makePath: /collections/collection2/leader_elect/shard3/election
   [junit4]   2> 473619 T1484 oascc.SolrZkClient.makePath makePath: /collections/collection2/leaders/shard3
   [junit4]   2> 473628 T1540 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 473628 T1540 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 473629 T1540 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 473631 T1540 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 473631 T1541 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 473637 T1541 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> 473637 T1541 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
   [junit4]   2> 473638 T1541 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard2
   [junit4]   2> 473641 T1540 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 473744 T1544 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> 473744 T1538 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> 474131 T1484 oascc.SolrZkClient.makePath makePath: /collections/collection2/leader_elect/shard2/election
   [junit4]   2> 474140 T1484 oascc.SolrZkClient.makePath makePath: /collections/collection2/leaders/shard2
   [junit4]   2> 474147 T1540 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 474148 T1540 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 474148 T1540 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 474150 T1541 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 474155 T1540 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 474259 T1538 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> 474259 T1544 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> 474304 T1484 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:58216 58216
   [junit4]   2> 474525 T1528 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:58216 58216
   [junit4]   2> 474527 T1484 oas.SolrTestCaseJ4.tearDown ###Ending testBadQueueItem
   [junit4]   2> 474527 T1541 oasc.Overseer$ClusterStateUpdater.run Overseer Loop exiting : 127.0.0.1:58216_solr
   [junit4]   2> 474529 T1545 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> 474536 T1484 oas.SolrTestCaseJ4.setUp ###Starting testShardAssignmentBigger
   [junit4]   2> 474537 T1484 oasc.ZkTestServer.run STARTING ZK TEST SERVER
   [junit4]   1> client port:0.0.0.0/0.0.0.0:0
   [junit4]   2> 474538 T1546 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
   [junit4]   2> 474638 T1484 oasc.ZkTestServer.run start zk server on port:55081
   [junit4]   2> 474639 T1484 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 474643 T1552 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@ba6dcc name:ZooKeeperConnection Watcher:127.0.0.1:55081 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 474643 T1484 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 474647 T1484 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 474654 T1554 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@d31a4b name:ZooKeeperConnection Watcher:127.0.0.1:55081 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 474654 T1484 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 474655 T1484 oascc.SolrZkClient.makePath makePath: /solr
   [junit4]   2> 474660 T1484 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 474662 T1556 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@14cd55d name:ZooKeeperConnection Watcher:127.0.0.1:55081/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 474663 T1484 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 474663 T1484 oascc.SolrZkClient.makePath makePath: /live_nodes
   [junit4]   2> 474667 T1484 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 474668 T1558 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@13cb9d2 name:ZooKeeperConnection Watcher:127.0.0.1:55081/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 474669 T1484 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 474671 T1484 oascc.SolrZkClient.makePath makePath: /overseer_elect
   [junit4]   2> 474676 T1484 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
   [junit4]   2> 474682 T1484 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:55081_solr
   [junit4]   2> 474683 T1484 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
   [junit4]   2> 474687 T1484 oasc.Overseer.start Overseer (id=91678078404067331-127.0.0.1:55081_solr-n_0000000000) starting
   [junit4]   2> 474691 T1484 oascc.SolrZkClient.makePath makePath: /overseer/queue
   [junit4]   2> 474696 T1484 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
   [junit4]   2> 474701 T1484 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-failure
   [junit4]   2> 474706 T1484 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-running
   [junit4]   2> 474711 T1484 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-completed
   [junit4]   2> 474717 T1484 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
   [junit4]   2> 474726 T1560 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
   [junit4]   2> 474727 T1484 oascc.SolrZkClient.makePath makePath: /clusterstate.json
   [junit4]   2> 474727 T1560 oasc.OverseerCollectionProcessor.prioritizeOverseerNodes prioritizing overseer nodes at 127.0.0.1:55081_solr
   [junit4]   2> 474727 T1559 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
   [junit4]   2> 474730 T1484 oascc.SolrZkClient.makePath makePath: /aliases.json
   [junit4]   2> 474733 T1484 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 474737 T1484 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 474739 T1562 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@a4a129 name:ZooKeeperConnection Watcher:127.0.0.1:55081/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 474740 T1484 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 474742 T1484 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 474746 T1484 oascc.SolrZkClient.makePath makePath: /live_nodes/node0
   [junit4]   2> 474751 T1484 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 474753 T1564 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@63f701 name:ZooKeeperConnection Watcher:127.0.0.1:55081/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 474753 T1484 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 474755 T1484 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 474758 T1484 oascc.SolrZkClient.makePath makePath: /live_nodes/node1
   [junit4]   2> 474763 T1484 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 474764 T1566 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@db4b61 name:ZooKeeperConnection Watcher:127.0.0.1:55081/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 474765 T1484 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 474767 T1484 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 474769 T1484 oascc.SolrZkClient.makePath makePath: /live_nodes/node2
   [junit4]   2> 474773 T1484 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 474775 T1568 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@105427d name:ZooKeeperConnection Watcher:127.0.0.1:55081/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 474776 T1484 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 474777 T1484 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 474780 T1484 oascc.SolrZkClient.makePath makePath: /live_nodes/node3
   [junit4]   2> 474785 T1484 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 474787 T1570 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@154545f name:ZooKeeperConnection Watcher:127.0.0.1:55081/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 474788 T1484 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 474790 T1484 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 474793 T1484 oascc.SolrZkClient.makePath makePath: /live_nodes/node4
   [junit4]   2> 474798 T1484 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 474799 T1572 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@6583ce name:ZooKeeperConnection Watcher:127.0.0.1:55081/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 474800 T1484 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 474802 T1484 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 474806 T1484 oascc.SolrZkClient.makePath makePath: /live_nodes/node5
   [junit4]   2> 474811 T1484 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 474812 T1574 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@165d0f4 name:ZooKeeperConnection Watcher:127.0.0.1:55081/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 474813 T1484 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 474815 T1484 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 474819 T1484 oascc.SolrZkClient.makePath makePath: /live_nodes/node6
   [junit4]   2> 474824 T1484 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 474826 T1576 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@26ff91 name:ZooKeeperConnection Watcher:127.0.0.1:55081/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 474826 T1484 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 474828 T1484 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 474832 T1484 oascc.SolrZkClient.makePath makePath: /live_nodes/node7
   [junit4]   2> 474838 T1484 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 474839 T1578 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@152cff6 name:ZooKeeperConnection Watcher:127.0.0.1:55081/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 474840 T1484 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 474842 T1484 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 474845 T1484 oascc.SolrZkClient.makePath makePath: /live_nodes/node8
   [junit4]   2> 474850 T1484 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 474852 T1580 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@e87340 name:ZooKeeperConnection Watcher:127.0.0.1:55081/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 474852 T1484 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 474855 T1484 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 474859 T1484 oascc.SolrZkClient.makePath makePath: /live_nodes/node9
   [junit4]   2> 474866 T1484 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 474867 T1582 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1f21265 name:ZooKeeperConnection Watcher:127.0.0.1:55081/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 474868 T1484 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 474870 T1484 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 474873 T1484 oascc.SolrZkClient.makePath makePath: /live_nodes/node10
   [junit4]   2> 474880 T1484 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 474882 T1584 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@30e366 name:ZooKeeperConnection Watcher:127.0.0.1:55081/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 474882 T1484 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 474884 T1484 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 474888 T1484 oascc.SolrZkClient.makePath makePath: /live_nodes/node11
   [junit4]   2> 474894 T1484 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 474896 T1586 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1c43644 name:ZooKeeperConnection Watcher:127.0.0.1:55081/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 474896 T1484 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 474898 T1484 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 474902 T1484 oascc.SolrZkClient.makePath makePath: /live_nodes/node12
   [junit4]   2> 474908 T1484 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 474910 T1588 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@14a3af1 name:ZooKeeperConnection Watcher:127.0.0.1:55081/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 474910 T1484 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 474913 T1484 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 474916 T1484 oascc.SolrZkClient.makePath makePath: /live_nodes/node13
   [junit4]   2> 474923 T1484 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 474925 T1590 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@ee8ed1 name:ZooKeeperConnection Watcher:127.0.0.1:55081/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 474925 T1484 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 474927 T1484 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 474931 T1484 oascc.SolrZkClient.makePath makePath: /live_nodes/node14
   [junit4]   2> 474938 T1484 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 474940 T1592 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1b86a51 name:ZooKeeperConnection Watcher:127.0.0.1:55081/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 474940 T1484 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 474942 T1484 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 474946 T1484 oascc.SolrZkClient.makePath makePath: /live_nodes/node15
   [junit4]   2> 474952 T1484 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 474954 T1594 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@16ecef2 name:ZooKeeperConnection Watcher:127.0.0.1:55081/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 474954 T1484 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 474956 T1484 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 474960 T1484 oascc.SolrZkClient.makePath makePath: /live_nodes/node16
   [junit4]   2> 474968 T1484 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 474969 T1596 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1f75e8e name:ZooKeeperConnection Watcher:127.0.0.1:55081/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 474970 T1484 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 474972 T1484 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 474975 T1484 oascc.SolrZkClient.makePath makePath: /live_nodes/node17
   [junit4]   2> 474982 T1484 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 474984 T1598 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@16d9b08 name:ZooKeeperConnection Watcher:127.0.0.1:55081/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 474985 T1484 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 474986 T1484 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 474990 T1484 oascc.SolrZkClient.makePath makePath: /live_nodes/node18
   [junit4]   2> 474998 T1484 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 475000 T1600 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@f74f88 name:ZooKeeperConnection Watcher:127.0.0.1:55081/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 475001 T1484 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 475003 T1484 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 475006 T1484 oascc.SolrZkClient.makePath makePath: /live_nodes/node19
   [junit4]   2> 475013 T1484 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 475015 T1602 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@e32b3c name:ZooKeeperConnection Watcher:127.0.0.1:55081/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 475015 T1484 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 475017 T1484 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 475020 T1484 oascc.SolrZkClient.makePath makePath: /live_nodes/node20
   [junit4]   2> 475027 T1484 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 475029 T1604 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@119956 name:ZooKeeperConnection Watcher:127.0.0.1:55081/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 475029 T1484 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 475031 T1484 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 475034 T1484 oascc.SolrZkClient.makePath makePath: /live_nodes/node21
   [junit4]   2> 475041 T1484 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 475043 T1606 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@be9eca name:ZooKeeperConnection Watcher:127.0.0.1:55081/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 475044 T1484 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 475045 T1484 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 475048 T1484 oascc.SolrZkClient.makePath makePath: /live_nodes/node22
   [junit4]   2> 475055 T1484 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 475056 T1608 oascc.ConnectionManager.process Watcher org.apache

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

ection1",
   [junit4]   2> 	  "core":"core1",
   [junit4]   2> 	  "roles":"",
   [junit4]   2> 	  "state":"active"}
   [junit4]   2> 493063 T2031 oasc.Overseer$ClusterStateUpdater.updateState node=core_node1 is already registered
   [junit4]   2> 493063 T2031 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
   [junit4]   2> 493065 T2030 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 493168 T2024 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 0)
   [junit4]   2> 493214 T1484 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:39532 39532
   [junit4]   2> 493350 T2018 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:39532 39532
   [junit4]   2> 493351 T1484 oas.SolrTestCaseJ4.tearDown ###Ending testStateChange
   [junit4]   2> 493352 T2031 oasc.Overseer$ClusterStateUpdater.run Overseer Loop exiting : 127.0.0.1:39532_solr
   [junit4]   2> 493352 T2033 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> 493353 T1484 oas.SolrTestCaseJ4.initCore ####initCore
   [junit4]   2> 493353 T1484 oas.SolrTestCaseJ4.initCore ####initCore end
   [junit4]   2> 494217 T2016 oasc.LeaderElector$ElectionWatcher.process WARN  org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /collections/collection1/leader_elect/shard3/election
   [junit4]   2> 	at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
   [junit4]   2> 	at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
   [junit4]   2> 	at org.apache.zookeeper.ZooKeeper.getChildren(ZooKeeper.java:1472)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:260)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:257)
   [junit4]   2> 	at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient.getChildren(SolrZkClient.java:257)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:94)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector.access$200(LeaderElector.java:55)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector$ElectionWatcher.process(LeaderElector.java:303)
   [junit4]   2> 	at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:522)
   [junit4]   2> 	at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:498)
   [junit4]   2> 
   [junit4]   2> 494218 T2016 oasc.LeaderElector$ElectionWatcher.process WARN  org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /collections/collection1/leader_elect/shard2/election
   [junit4]   2> 	at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
   [junit4]   2> 	at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
   [junit4]   2> 	at org.apache.zookeeper.ZooKeeper.getChildren(ZooKeeper.java:1472)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:260)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:257)
   [junit4]   2> 	at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient.getChildren(SolrZkClient.java:257)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:94)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector.access$200(LeaderElector.java:55)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector$ElectionWatcher.process(LeaderElector.java:303)
   [junit4]   2> 	at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:522)
   [junit4]   2> 	at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:498)
   [junit4]   2> 
   [junit4]   2> 494219 T2016 oasc.LeaderElector$ElectionWatcher.process WARN  org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /collections/collection1/leader_elect/shard1/election
   [junit4]   2> 	at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
   [junit4]   2> 	at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
   [junit4]   2> 	at org.apache.zookeeper.ZooKeeper.getChildren(ZooKeeper.java:1472)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:260)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:257)
   [junit4]   2> 	at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient.getChildren(SolrZkClient.java:257)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:94)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector.access$200(LeaderElector.java:55)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector$ElectionWatcher.process(LeaderElector.java:303)
   [junit4]   2> 	at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:522)
   [junit4]   2> 	at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:498)
   [junit4]   2> 
   [junit4]   2> 496354 T1484 oas.SolrTestCaseJ4.deleteCore ###deleteCore
   [junit4]   2> NOTE: leaving temporary files on disk at: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./solr.cloud.OverseerTest-1BF320DFA26F524F-001
   [junit4]   2> NOTE: test params are: codec=Lucene46: {}, docValues:{}, sim=DefaultSimilarity, locale=vi_VN, timezone=Africa/Juba
   [junit4]   2> NOTE: Linux 3.8.0-38-generic i386/Oracle Corporation 1.7.0_55 (32-bit)/cpus=8,threads=1,free=170446392,total=298057728
   [junit4]   2> NOTE: All tests run in this JVM: [ShardRoutingTest, MoreLikeThisHandlerTest, SimpleFacetsTest, TestRequestStatusCollectionAPI, TestSort, CacheHeaderTest, SliceStateUpdateTest, TestExtendedDismaxParser, ResponseLogComponentTest, TestSearcherReuse, ExternalFileFieldSortTest, TestQueryUtils, EnumFieldTest, TestDocSet, SuggesterFSTTest, TestBadConfig, LoggingHandlerTest, URLClassifyProcessorTest, TestSurroundQueryParser, OverseerCollectionProcessorTest, AnalysisErrorHandlingTest, TestSearchPerf, HdfsWriteToMultipleCollectionsTest, TestRemoteStreaming, TestSolrIndexConfig, TestSolrXml, TestGroupingSearch, CircularListTest, SliceStateTest, TestNRTOpen, TestOverriddenPrefixQueryForCustomFieldType, CoreMergeIndexesAdminHandlerTest, TestRandomDVFaceting, SynonymTokenizerTest, SpatialFilterTest, RecoveryZkTest, DirectUpdateHandlerOptimizeTest, TestFieldTypeResource, TestFunctionQuery, TestCharFilters, TestDocBasedVersionConstraints, DistribDocExpirationUpdateProcessorTest, FieldFacetExtrasTest, FieldMutatingUpdateProcessorTest, TestManagedResource, DocumentBuilderTest, TestRecoveryHdfs, PreAnalyzedFieldTest, TestSimpleQParserPlugin, DistributedQueryComponentCustomSortTest, SearchHandlerTest, SpellingQueryConverterTest, CursorMarkTest, TestNonNRTOpen, FileBasedSpellCheckerTest, TestConfig, BasicDistributedZkTest, TestPseudoReturnFields, OverseerTest]
   [junit4] Completed on J0 in 44.96s, 9 tests, 1 error <<< FAILURES!

[...truncated 865 lines...]
BUILD FAILED
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/build.xml:467: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/build.xml:447: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/build.xml:45: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/extra-targets.xml:37: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build.xml:189: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/common-build.xml:496: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/lucene/common-build.xml:1296: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/lucene/common-build.xml:920: There were test failures: 398 suites, 1669 tests, 1 error, 37 ignored (16 assumptions)

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



Mime
View raw message