You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@lucene.apache.org by Apache Jenkins Server <je...@builds.apache.org> on 2014/01/08 01:50:18 UTC

[JENKINS] Lucene-Solr-Tests-4.x-Java6 - Build # 2261 - Failure

Build: https://builds.apache.org/job/Lucene-Solr-Tests-4.x-Java6/2261/

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

Error Message:
KeeperErrorCode = NodeExists for /collections/collection1/leaders/shard1

Stack Trace:
org.apache.zookeeper.KeeperException$NodeExistsException: KeeperErrorCode = NodeExists for /collections/collection1/leaders/shard1
	at __randomizedtesting.SeedInfo.seed([9ACAAB8047B4E3C9:9EC2247355110CE8]:0)
	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:428)
	at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
	at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:425)
	at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:382)
	at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:369)
	at org.apache.solr.cloud.ShardLeaderElectionContextBase.runLeaderProcess(ElectionContext.java:112)
	at org.apache.solr.cloud.LeaderElector.runIamLeaderProcess(LeaderElector.java:165)
	at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:109)
	at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:157)
	at org.apache.solr.cloud.LeaderElector.joinElection(LeaderElector.java:277)
	at org.apache.solr.cloud.OverseerTest$MockZKController.publishState(OverseerTest.java:153)
	at org.apache.solr.cloud.OverseerTest.testOverseerFailure(OverseerTest.java:584)
	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:616)
	at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1559)
	at com.carrotsearch.randomizedtesting.RandomizedRunner.access$600(RandomizedRunner.java:79)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:737)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:773)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:787)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
	at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:50)
	at org.apache.lucene.util.TestRuleFieldCacheSanity$1.evaluate(TestRuleFieldCacheSanity.java:51)
	at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
	at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:49)
	at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
	at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:782)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:442)
	at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:746)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:648)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:682)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:693)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
	at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
	at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:42)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
	at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
	at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:43)
	at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
	at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
	at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:55)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
	at java.lang.Thread.run(Thread.java:679)




Build Log:
[...truncated 9852 lines...]
   [junit4] Suite: org.apache.solr.cloud.OverseerTest
   [junit4]   2> 1478621 T2941 oas.SolrTestCaseJ4.initCore ####initCore
   [junit4]   2> Creating dataDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./solrtest-OverseerTest-1389141481334
   [junit4]   2> 1478622 T2941 oas.SolrTestCaseJ4.initCore ####initCore end
   [junit4]   2> 1478626 T2941 oas.SolrTestCaseJ4.setUp ###Starting testDoubleAssignment
   [junit4]   2> 1478626 T2941 oasc.ZkTestServer.run STARTING ZK TEST SERVER
   [junit4]   2> 1478627 T2942 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
   [junit4]   2> 1478728 T2941 oasc.ZkTestServer.run start zk server on port:47181
   [junit4]   2> 1478729 T2941 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1478733 T2948 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@4100f4d4 name:ZooKeeperConnection Watcher:127.0.0.1:47181/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1478734 T2941 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1478735 T2941 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1478737 T2950 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@31af22ca name:ZooKeeperConnection Watcher:127.0.0.1:47181 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1478737 T2941 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1478758 T2941 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1478760 T2952 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@2bb74112 name:ZooKeeperConnection Watcher:127.0.0.1:47181 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1478760 T2941 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1478760 T2941 oascc.SolrZkClient.makePath makePath: /solr
   [junit4]   2> 1478770 T2941 oascc.SolrZkClient.makePath makePath: /live_nodes
   [junit4]   2> 1478773 T2941 oascc.SolrZkClient.makePath makePath: /clusterstate.json
   [junit4]   2> 1478776 T2941 oascc.SolrZkClient.makePath makePath: /aliases.json
   [junit4]   2> 1478778 T2941 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 1478782 T2941 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1478784 T2954 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@198cbfa4 name:ZooKeeperConnection Watcher:127.0.0.1:47181/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1478784 T2941 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1478785 T2941 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 1478787 T2941 oascc.SolrZkClient.makePath makePath: /live_nodes/node1
   [junit4]   2> 1478790 T2948 oascc.ZkStateReader$3.process Updating live nodes... (1)
   [junit4]   2> 1478790 T2954 oascc.ZkStateReader$3.process Updating live nodes... (1)
   [junit4]   2> 1478791 T2941 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1478793 T2956 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@14a3b7fa name:ZooKeeperConnection Watcher:127.0.0.1:47181/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1478793 T2941 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1478794 T2941 oascc.SolrZkClient.makePath makePath: /overseer_elect
   [junit4]   2> 1478797 T2941 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
   [junit4]   2> 1478808 T2941 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
   [junit4]   2> 1478810 T2941 oasc.Overseer.start Overseer (id=91038776121491460-127.0.0.1:47181_solr-n_0000000000) starting
   [junit4]   2> 1478823 T2941 oascc.SolrZkClient.makePath makePath: /overseer/queue
   [junit4]   2> 1478831 T2941 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
   [junit4]   2> 1478840 T2941 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
   [junit4]   2> 1478843 T2958 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
   [junit4]   2> 1478844 T2957 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
   [junit4]   2> 1478853 T2957 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1478853 T2957 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> 1478853 T2957 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1]
   [junit4]   2> 1478854 T2957 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
   [junit4]   2> 1478856 T2956 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1478866 T2948 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> 1478866 T2954 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> 1479353 T2941 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
   [junit4]   2> 1479371 T2941 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 1479377 T2956 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1479377 T2941 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1479378 T2957 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1479380 T2948 oascc.ZkStateReader$3.process Updating live nodes... (0)
   [junit4]   2> 1479380 T2954 oascc.ZkStateReader$3.process Updating live nodes... (0)
   [junit4]   2> 1479381 T2941 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1479382 T2956 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1479383 T2960 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@4d19f40b name:ZooKeeperConnection Watcher:127.0.0.1:47181/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1479384 T2941 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1479385 T2941 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 1479387 T2941 oascc.SolrZkClient.makePath makePath: /live_nodes/node1
   [junit4]   2> 1479389 T2948 oascc.ZkStateReader$3.process Updating live nodes... (1)
   [junit4]   2> 1479390 T2960 oascc.ZkStateReader$3.process Updating live nodes... (1)
   [junit4]   2> 1479398 T2956 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1479398 T2941 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
   [junit4]   2> 1479399 T2957 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> 1479399 T2957 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
   [junit4]   2> 1479411 T2956 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1479413 T2941 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 1479417 T2956 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1479421 T2956 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1479523 T2948 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> 1479523 T2960 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> 1479523 T2941 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1479536 T2948 oascc.ZkStateReader$3.process Updating live nodes... (0)
   [junit4]   2> 1479536 T2960 oascc.ZkStateReader$3.process Updating live nodes... (0)
   [junit4]   2> 1479539 T2941 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:47181 47181
   [junit4]   2> 1479614 T2941 oas.SolrTestCaseJ4.tearDown ###Ending testDoubleAssignment
   [junit4]   1> client port:0.0.0.0/0.0.0.0:0
   [junit4]   2> 1479620 T2941 oas.SolrTestCaseJ4.setUp ###Starting testOverseerFailure
   [junit4]   2> 1479620 T2941 oasc.ZkTestServer.run STARTING ZK TEST SERVER
   [junit4]   2> 1479621 T2961 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
   [junit4]   2> 1479722 T2941 oasc.ZkTestServer.run start zk server on port:47188
   [junit4]   2> 1479723 T2941 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1479726 T2967 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@774867a6 name:ZooKeeperConnection Watcher:127.0.0.1:47188/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1479726 T2941 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1479727 T2941 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1479729 T2969 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@2c8ae0e3 name:ZooKeeperConnection Watcher:127.0.0.1:47188 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1479729 T2941 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1479796 T2941 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1479798 T2971 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@753d57bb name:ZooKeeperConnection Watcher:127.0.0.1:47188 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1479798 T2941 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1479798 T2941 oascc.SolrZkClient.makePath makePath: /solr
   [junit4]   2> 1479801 T2941 oascc.SolrZkClient.makePath makePath: /live_nodes
   [junit4]   2> 1479803 T2941 oascc.SolrZkClient.makePath makePath: /clusterstate.json
   [junit4]   2> 1479805 T2941 oascc.SolrZkClient.makePath makePath: /aliases.json
   [junit4]   2> 1479807 T2941 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 1479809 T2941 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1479811 T2973 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@a8b4ced name:ZooKeeperConnection Watcher:127.0.0.1:47188/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1479811 T2941 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1479812 T2941 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 1479814 T2941 oascc.SolrZkClient.makePath makePath: /live_nodes/node1
   [junit4]   2> 1479816 T2967 oascc.ZkStateReader$3.process Updating live nodes... (1)
   [junit4]   2> 1479817 T2973 oascc.ZkStateReader$3.process Updating live nodes... (1)
   [junit4]   2> 1479817 T2941 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1479819 T2975 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@2c72c20d name:ZooKeeperConnection Watcher:127.0.0.1:47188/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1479819 T2941 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1479820 T2941 oascc.SolrZkClient.makePath makePath: /overseer_elect
   [junit4]   2> 1479822 T2941 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
   [junit4]   2> 1479827 T2941 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
   [junit4]   2> 1479836 T2941 oasc.Overseer.start Overseer (id=91038776186699780-127.0.0.1:47188_solr-n_0000000000) starting
   [junit4]   2> 1479844 T2941 oascc.SolrZkClient.makePath makePath: /overseer/queue
   [junit4]   2> 1479848 T2941 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
   [junit4]   2> 1479859 T2941 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
   [junit4]   2> 1479862 T2977 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
   [junit4]   2> 1479862 T2976 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
   [junit4]   2> 1480864 T2975 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1480866 T2976 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1480866 T2976 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> 1480867 T2976 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1]
   [junit4]   2> 1480867 T2976 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
   [junit4]   2> 1480876 T2975 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1480877 T2967 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> 1480877 T2973 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> 1481365 T2941 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
   [junit4]   2> 1481384 T2941 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 1481390 T2975 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1481390 T2941 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1481391 T2976 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1481393 T2975 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1481394 T2941 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
   [junit4]   2> 1481396 T2976 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> 1481396 T2976 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
   [junit4]   2> 1481409 T2975 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1481512 T2967 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> 1481512 T2973 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> 1482569 T2941 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
   [junit4]   2> 1482589 T2941 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1482591 T2979 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@712e6f2f name:ZooKeeperConnection Watcher:127.0.0.1:47188/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1482591 T2941 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1482595 T2941 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
   [junit4]   2> 1482603 T2941 oasc.Overseer.start Overseer (id=91038776186699781-127.0.0.1:47188_solr-n_0000000001) starting
   [junit4]   2> 1482608 T2981 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
   [junit4]   2> 1482609 T2980 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
   [junit4]   2> 1482610 T2980 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1482611 T2980 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> 1482611 T2980 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
   [junit4]   2> 1482614 T2979 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1482614 T2967 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> 1482614 T2973 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> 1482669 T2979 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1482669 T2941 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
   [junit4]   2> 1482670 T2980 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1482681 T2941 oasc.LeaderElector.checkIfIamLeader WARN Failed setting watch org.apache.zookeeper.KeeperException$NoNodeException: KeeperErrorCode = NoNode for /collections/collection1/leader_elect/shard1/election/91038776186699779-node1_core1-n_0000000002
   [junit4]   2> 	at org.apache.zookeeper.KeeperException.create(KeeperException.java:111)
   [junit4]   2> 	at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
   [junit4]   2> 	at org.apache.zookeeper.ZooKeeper.getData(ZooKeeper.java:1151)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:273)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:270)
   [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:270)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:126)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector.joinElection(LeaderElector.java:277)
   [junit4]   2> 	at org.apache.solr.cloud.OverseerTest$MockZKController.publishState(OverseerTest.java:153)
   [junit4]   2> 	at org.apache.solr.cloud.OverseerTest.testOverseerFailure(OverseerTest.java:584)
   [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:616)
   [junit4]   2> 	at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1559)
   [junit4]   2> 	at com.carrotsearch.randomizedtesting.RandomizedRunner.access$600(RandomizedRunner.java:79)
   [junit4]   2> 	at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:737)
   [junit4]   2> 	at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:773)
   [junit4]   2> 	at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:787)
   [junit4]   2> 	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
   [junit4]   2> 	at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:50)
   [junit4]   2> 	at org.apache.lucene.util.TestRuleFieldCacheSanity$1.evaluate(TestRuleFieldCacheSanity.java:51)
   [junit4]   2> 	at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
   [junit4]   2> 	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
   [junit4]   2> 	at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:49)
   [junit4]   2> 	at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
   [junit4]   2> 	at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
   [junit4]   2> 	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
   [junit4]   2> 	at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
   [junit4]   2> 	at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:782)
   [junit4]   2> 	at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:442)
   [junit4]   2> 	at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:746)
   [junit4]   2> 	at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:648)
   [junit4]   2> 	at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:682)
   [junit4]   2> 	at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:693)
   [junit4]   2> 	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
   [junit4]   2> 	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
   [junit4]   2> 	at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
   [junit4]   2> 	at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:42)
   [junit4]   2> 	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
   [junit4]   2> 	at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
   [junit4]   2> 	at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
   [junit4]   2> 	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
   [junit4]   2> 	at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:43)
   [junit4]   2> 	at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
   [junit4]   2> 	at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
   [junit4]   2> 	at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:55)
   [junit4]   2> 	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
   [junit4]   2> 	at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
   [junit4]   2> 	at java.lang.Thread.run(Thread.java:679)
   [junit4]   2> 
   [junit4]   2> 1482683 T2973 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 1482684 T2980 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:173)
   [junit4]   2> 		at org.apache.solr.common.cloud.SolrZkClient$2.execute(SolrZkClient.java:170)
   [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:170)
   [junit4]   2> 		at org.apache.solr.common.cloud.SolrZkClient.clean(SolrZkClient.java:654)
   [junit4]   2> 		at org.apache.solr.common.cloud.SolrZkClient.clean(SolrZkClient.java:649)
   [junit4]   2> 		at org.apache.solr.common.cloud.SolrZkClient.clean(SolrZkClient.java:649)
   [junit4]   2> 		at org.apache.solr.common.cloud.SolrZkClient.clean(SolrZkClient.java:649)
   [junit4]   2> 		at org.apache.solr.cloud.Overseer$ClusterStateUpdater.removeCore(Overseer.java:875)
   [junit4]   2> 		at org.apache.solr.cloud.Overseer$ClusterStateUpdater.processMessage(Overseer.java:226)
   [junit4]   2> 		at org.apache.solr.cloud.Overseer$ClusterStateUpdater.run(Overseer.java:187)
   [junit4]   2> 		at java.lang.Thread.run(Thread.java:679)
   [junit4]   2> 	
   [junit4]   2> 1482685 T2941 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 1482687 T2979 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1482690 T2979 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1482691 T2967 oascc.ZkStateReader$3.process Updating live nodes... (0)
   [junit4]   2> 1482691 T2980 oasc.Overseer$ClusterStateUpdater.setShardLeader ERROR Could not mark shard leader for non existing collection:collection1
   [junit4]   2> 1482695 T2941 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:47188 47188
   [junit4]   2> 1483997 T2941 oas.SolrTestCaseJ4.tearDown ###Ending testOverseerFailure
   [junit4]   1> client port:0.0.0.0/0.0.0.0:0
   [junit4]   2> NOTE: reproduce with: ant test  -Dtestcase=OverseerTest -Dtests.method=testOverseerFailure -Dtests.seed=9ACAAB8047B4E3C9 -Dtests.multiplier=3 -Dtests.slow=true -Dtests.locale=es_PR -Dtests.timezone=Atlantic/Reykjavik -Dtests.file.encoding=US-ASCII
   [junit4] ERROR   4.39s J0 | OverseerTest.testOverseerFailure <<<
   [junit4]    > Throwable #1: org.apache.zookeeper.KeeperException$NodeExistsException: KeeperErrorCode = NodeExists for /collections/collection1/leaders/shard1
   [junit4]    > 	at __randomizedtesting.SeedInfo.seed([9ACAAB8047B4E3C9:9EC2247355110CE8]:0)
   [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:428)
   [junit4]    > 	at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
   [junit4]    > 	at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:425)
   [junit4]    > 	at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:382)
   [junit4]    > 	at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:369)
   [junit4]    > 	at org.apache.solr.cloud.ShardLeaderElectionContextBase.runLeaderProcess(ElectionContext.java:112)
   [junit4]    > 	at org.apache.solr.cloud.LeaderElector.runIamLeaderProcess(LeaderElector.java:165)
   [junit4]    > 	at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:109)
   [junit4]    > 	at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:157)
   [junit4]    > 	at org.apache.solr.cloud.LeaderElector.joinElection(LeaderElector.java:277)
   [junit4]    > 	at org.apache.solr.cloud.OverseerTest$MockZKController.publishState(OverseerTest.java:153)
   [junit4]    > 	at org.apache.solr.cloud.OverseerTest.testOverseerFailure(OverseerTest.java:584)
   [junit4]    > 	at java.lang.Thread.run(Thread.java:679)
   [junit4]   2> 1484014 T2941 oas.SolrTestCaseJ4.setUp ###Starting testStateChange
   [junit4]   2> 1484015 T2941 oasc.ZkTestServer.run STARTING ZK TEST SERVER
   [junit4]   2> 1484015 T2982 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
   [junit4]   2> 1484116 T2941 oasc.ZkTestServer.run start zk server on port:47195
   [junit4]   2> 1484117 T2941 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1484120 T2988 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1ddfb68 name:ZooKeeperConnection Watcher:127.0.0.1:47195/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1484120 T2941 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1484122 T2941 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1484123 T2990 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@6cba545e name:ZooKeeperConnection Watcher:127.0.0.1:47195 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1484124 T2941 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1484190 T2941 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1484191 T2992 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@7c541c68 name:ZooKeeperConnection Watcher:127.0.0.1:47195 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1484192 T2973 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 1484192 T2941 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1484192 T2941 oascc.SolrZkClient.makePath makePath: /solr
   [junit4]   2> 1484192 T2973 oasc.LeaderElector$1.process WARN  org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /collections
   [junit4]   2> 	at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
   [junit4]   2> 	at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
   [junit4]   2> 	at org.apache.zookeeper.ZooKeeper.exists(ZooKeeper.java:1041)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient$3.execute(SolrZkClient.java:205)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient$3.execute(SolrZkClient.java:202)
   [junit4]   2> 	at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient.exists(SolrZkClient.java:202)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:413)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:382)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:369)
   [junit4]   2> 	at org.apache.solr.cloud.ShardLeaderElectionContextBase.runLeaderProcess(ElectionContext.java:112)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector.runIamLeaderProcess(LeaderElector.java:165)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:109)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector.access$000(LeaderElector.java:55)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector$1.process(LeaderElector.java:138)
   [junit4]   2> 	at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:519)
   [junit4]   2> 	at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:495)
   [junit4]   2> 
   [junit4]   2> 1484193 T2973 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
   [junit4]   2> 1484195 T2941 oascc.SolrZkClient.makePath makePath: /live_nodes
   [junit4]   2> 1484197 T2941 oascc.SolrZkClient.makePath makePath: /clusterstate.json
   [junit4]   2> 1484199 T2941 oascc.SolrZkClient.makePath makePath: /aliases.json
   [junit4]   2> 1484201 T2941 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 1484204 T2941 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1484205 T2994 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@4b6cc34c name:ZooKeeperConnection Watcher:127.0.0.1:47195/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1484206 T2941 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1484207 T2941 oascc.SolrZkClient.makePath makePath: /overseer_elect
   [junit4]   2> 1484209 T2941 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
   [junit4]   2> 1484213 T2941 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
   [junit4]   2> 1484215 T2941 oasc.Overseer.start Overseer (id=91038776474927107-127.0.0.1:47195_solr-n_0000000000) starting
   [junit4]   2> 1484217 T2941 oascc.SolrZkClient.makePath makePath: /overseer/queue
   [junit4]   2> 1484220 T2941 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
   [junit4]   2> 1484223 T2941 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
   [junit4]   2> 1484226 T2996 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
   [junit4]   2> 1484227 T2995 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
   [junit4]   2> 1484228 T2941 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1484229 T2995 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1484229 T2995 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=null message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "base_url":"http://127.0.0.1/solr",
   [junit4]   2> 	  "node_name":"node1",
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "core":"core1",
   [junit4]   2> 	  "roles":"",
   [junit4]   2> 	  "state":"recovering"}
   [junit4]   2> 1484230 T2995 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
   [junit4]   2> 1484232 T2994 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1484233 T2988 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> 1484280 T2941 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1484282 T2994 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1484283 T2995 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1484284 T2995 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=null message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "base_url":"http://127.0.0.1/solr",
   [junit4]   2> 	  "node_name":"node1",
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "core":"core1",
   [junit4]   2> 	  "roles":"",
   [junit4]   2> 	  "state":"active"}
   [junit4]   2> 1484284 T2995 oasc.Overseer$ClusterStateUpdater.updateState node=core_node1 is already registered
   [junit4]   2> 1484284 T2995 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
   [junit4]   2> 1484293 T2994 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1484395 T2988 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> 1484438 T2941 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:47195 47195
   [junit4]   2> 1484635 T2941 oas.SolrTestCaseJ4.tearDown ###Ending testStateChange
   [junit4]   1> client port:0.0.0.0/0.0.0.0:0
   [junit4]   2> 1484640 T2941 oas.SolrTestCaseJ4.setUp ###Starting testPlaceholders
   [junit4]   2> 1484641 T2941 oasc.ZkTestServer.run STARTING ZK TEST SERVER
   [junit4]   2> 1484641 T2997 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
   [junit4]   2> 1484742 T2941 oasc.ZkTestServer.run start zk server on port:47200
   [junit4]   2> 1484743 T2941 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1484747 T3003 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@35d6f543 name:ZooKeeperConnection Watcher:127.0.0.1:47200/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1484747 T2941 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1484748 T2941 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1484750 T3005 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@3bba665 name:ZooKeeperConnection Watcher:127.0.0.1:47200 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1484750 T2941 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1484788 T2941 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1484790 T3007 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@41d35e9 name:ZooKeeperConnection Watcher:127.0.0.1:47200 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1484790 T2941 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1484791 T2941 oascc.SolrZkClient.makePath makePath: /solr
   [junit4]   2> 1484793 T2941 oascc.SolrZkClient.makePath makePath: /live_nodes
   [junit4]   2> 1484796 T2941 oascc.SolrZkClient.makePath makePath: /clusterstate.json
   [junit4]   2> 1484798 T2941 oascc.SolrZkClient.makePath makePath: /aliases.json
   [junit4]   2> 1484800 T2941 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 1484802 T2941 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1484804 T3009 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@5f442e8 name:ZooKeeperConnection Watcher:127.0.0.1:47200/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1484804 T2941 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1484805 T2941 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 1484807 T2941 oascc.SolrZkClient.makePath makePath: /live_nodes/node1
   [junit4]   2> 1484810 T3003 oascc.ZkStateReader$3.process Updating live nodes... (1)
   [junit4]   2> 1484810 T3009 oascc.ZkStateReader$3.process Updating live nodes... (1)
   [junit4]   2> 1484810 T2941 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1484812 T3011 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@700dcd22 name:ZooKeeperConnection Watcher:127.0.0.1:47200/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1484812 T2941 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1484813 T2941 oascc.SolrZkClient.makePath makePath: /overseer_elect
   [junit4]   2> 1484816 T2941 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
   [junit4]   2> 1484820 T2941 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
   [junit4]   2> 1484822 T2941 oasc.Overseer.start Overseer (id=91038776515821572-127.0.0.1:47200_solr-n_0000000000) starting
   [junit4]   2> 1484824 T2941 oascc.SolrZkClient.makePath makePath: /overseer/queue
   [junit4]   2> 1484827 T2941 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
   [junit4]   2> 1484830 T2941 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
   [junit4]   2> 1484833 T3013 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
   [junit4]   2> 1484834 T3012 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
   [junit4]   2> 1484844 T3012 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1484844 T3012 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=12 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"recovering",
   [junit4]   2> 	  "node_name":"node1",
   [junit4]   2> 	  "core":"core1",
   [junit4]   2> 	  "core_node_name":"node1",
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "numShards":"12",
   [junit4]   2> 	  "base_url":"http://node1/solr/"}
   [junit4]   2> 1484844 T3012 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1, shard2, shard3, shard4, shard5, shard6, shard7, shard8, shard9, shard10, shard11, shard12]
   [junit4]   2> 1484845 T3012 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
   [junit4]   2> 1484847 T3011 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1484857 T3009 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> 1484857 T3003 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> 1485344 T2941 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
   [junit4]   2> 1485364 T2941 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 1485370 T3011 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1485370 T2941 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1485371 T3012 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1485373 T3003 oascc.ZkStateReader$3.process Updating live nodes... (0)
   [junit4]   2> 1485373 T3009 oascc.ZkStateReader$3.process Updating live nodes... (0)
   [junit4]   2> 1485376 T2941 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:47200 47200
   [junit4]   2> 1485475 T2941 oas.SolrTestCaseJ4.tearDown ###Ending testPlaceholders
   [junit4]   1> client port:0.0.0.0/0.0.0.0:0
   [junit4]   2> 1485481 T2941 oas.SolrTestCaseJ4.setUp ###Starting testReplay
   [junit4]   2> 1485481 T2941 oasc.ZkTestServer.run STARTING ZK TEST SERVER
   [junit4]   2> 1485482 T3014 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
   [junit4]   2> 1485583 T2941 oasc.ZkTestServer.run start zk server on port:47206
   [junit4]   2> 1485584 T2941 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1485587 T3020 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@488291c3 name:ZooKeeperConnection Watcher:127.0.0.1:47206/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1485587 T2941 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1485588 T2941 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1485590 T3022 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@9a31c77 name:ZooKeeperConnection Watcher:127.0.0.1:47206 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1485590 T2941 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1485632 T2941 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1485634 T3024 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@6271048e name:ZooKeeperConnection Watcher:127.0.0.1:47206 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1485634 T2941 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1485634 T2941 oascc.SolrZkClient.makePath makePath: /solr
   [junit4]   2> 1485637 T2941 oascc.SolrZkClient.makePath makePath: /live_nodes
   [junit4]   2> 1485639 T2941 oascc.SolrZkClient.makePath makePath: /clusterstate.json
   [junit4]   2> 1485641 T2941 oascc.SolrZkClient.makePath makePath: /aliases.json
   [junit4]   2> 1485643 T2941 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 1485646 T2941 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
   [junit4]   2> 1485651 T2941 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1485652 T3026 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@45c3a8d6 name:ZooKeeperConnection Watcher:127.0.0.1:47206/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1485652 T2941 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1485653 T2941 oascc.SolrZkClient.makePath makePath: /overseer_elect
   [junit4]   2> 1485655 T2941 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
   [junit4]   2> 1485659 T2941 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
   [junit4]   2> 1485662 T2941 oasc.Overseer.start Overseer (id=91038776570871811-127.0.0.1:47206_solr-n_0000000000) starting
   [junit4]   2> 1485664 T2941 oascc.SolrZkClient.makePath makePath: /overseer/queue
   [junit4]   2> 1485668 T2941 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
   [junit4]   2> 1485670 T3028 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
   [junit4]   2> 1485672 T3027 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1485673 T3027 oasc.Overseer$ClusterStateUpdater.run Replaying operations from work queue.
   [junit4]   2> 1485673 T3027 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=null message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "base_url":"http://127.0.0.1/solr",
   [junit4]   2> 	  "node_name":"node1",
   [junit4]   2> 	  "shard":"s1",
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "core":"core1",
   [junit4]   2> 	  "roles":"",
   [junit4]   2> 	  "state":"recovering"}
   [junit4]   2> 1485675 T3020 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> 1485677 T3027 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=null message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "base_url":"http://127.0.0.1/solr",
   [junit4]   2> 	  "node_name":"node1",
   [junit4]   2> 	  "shard":"s1",
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "core":"core2",
   [junit4]   2> 	  "roles":"",
   [junit4]   2> 	  "state":"recovering"}
   [junit4]   2> 1485678 T3020 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> 1485680 T3027 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
   [junit4]   2> 1485681 T3027 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1485682 T3027 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=null message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "base_url":"http://127.0.0.1/solr",
   [junit4]   2> 	  "node_name":"node1",
   [junit4]   2> 	  "shard":"s1",
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "core":"core3",
   [junit4]   2> 	  "roles":"",
   [junit4]   2> 	  "state":"recovering"}
   [junit4]   2> 1485684 T3026 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1485685 T3020 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> 1485776 T2941 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:47206 47206
   [junit4]   2> 1485953 T2941 oas.SolrTestCaseJ4.tearDown ###Ending testReplay
   [junit4]   1> client port:0.0.0.0/0.0.0.0:0
   [junit4]   2> 1485959 T2941 oas.SolrTestCaseJ4.setUp ###Starting testShardAssignmentBigger
   [junit4]   2> 1485959 T2941 oasc.ZkTestServer.run STARTING ZK TEST SERVER
   [junit4]   2> 1485960 T3029 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
   [junit4]   2> 1486061 T2941 oasc.ZkTestServer.run start zk server on port:47211
   [junit4]   2> 1486062 T2941 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1486065 T3035 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@756e74e5 name:ZooKeeperConnection Watcher:127.0.0.1:47211 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1486066 T2941 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1486097 T2941 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1486099 T3037 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@25a39045 name:ZooKeeperConnection Watcher:127.0.0.1:47211 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1486099 T2941 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1486099 T2941 oascc.SolrZkClient.makePath makePath: /solr
   [junit4]   2> 1486102 T2941 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1486104 T3039 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@6da1cff4 name:ZooKeeperConnection Watcher:127.0.0.1:47211/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1486104 T2941 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1486105 T2941 oascc.SolrZkClient.makePath makePath: /live_nodes
   [junit4]   2> 1486107 T2941 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1486109 T3041 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@3e8ccbdd name:ZooKeeperConnection Watcher:127.0.0.1:47211/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1486109 T2941 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1486110 T2941 oascc.SolrZkClient.makePath makePath: /overseer_elect
   [junit4]   2> 1486112 T2941 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
   [junit4]   2> 1486116 T2941 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
   [junit4]   2> 1486118 T2941 oasc.Overseer.start Overseer (id=91038776602198019-127.0.0.1:47211_solr-n_0000000000) starting
   [junit4]   2> 1486120 T2941 oascc.SolrZkClient.makePath makePath: /overseer/queue
   [junit4]   2> 1486124 T2941 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
   [junit4]   2> 1486127 T2941 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
   [junit4]   2> 1486129 T3043 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
   [junit4]   2> 1486130 T2941 oascc.SolrZkClient.makePath makePath: /clusterstate.json
   [junit4]   2> 1486130 T3042 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
   [junit4]   2> 1486132 T2941 oascc.SolrZkClient.makePath makePath: /aliases.json
   [junit4]   2> 1486134 T2941 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 1486136 T2941 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1486138 T3045 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@3d38a184 name:ZooKeeperConnection Watcher:127.0.0.1:47211/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1486138 T2941 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1486139 T2941 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 1486141 T2941 oascc.SolrZkClient.makePath makePath: /live_nodes/node0
   [junit4]   2> 1486144 T3039 oascc.ZkStateReader$3.process Updating live nodes... (1)
   [junit4]   2> 1486144 T3045 oascc.ZkStateReader$3.process Updating live nodes... (1)
   [junit4]   2> 1486144 T2941 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1486146 T3047 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@7e2705f5 name:ZooKeeperConnection Watcher:127.0.0.1:47211/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1486146 T2941 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1486147 T2941 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 1486149 T2941 oascc.SolrZkClient.makePath makePath: /live_nodes/node1
   [junit4]   2> 1486152 T3045 oascc.ZkStateReader$3.process Updating live nodes... (2)
   [junit4]   2> 1486152 T3039 oascc.ZkStateReader$3.process Updating live nodes... (2)
   [junit4]   2> 1486152 T3047 oascc.ZkStateReader$3.process Updating live nodes... (2)
   [junit4]   2> 1486153 T2941 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1486154 T3049 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1987def7 name:ZooKeeperConnection Watcher:127.0.0.1:47211/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1486154 T2941 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1486156 T2941 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 1486158 T2941 oascc.SolrZkClient.makePath makePath: /live_nodes/node2
   [junit4]   2> 1486160 T3045 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 1486160 T3047 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 1486160 T3049 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 1486160 T3039 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 1486161 T2941 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1486162 T3051 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@2fd492e8 name:ZooKeeperConnection Watcher:127.0.0.1:47211/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1486163 T2941 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1486164 T2941 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 1486166 T2941 oascc.SolrZkClient.makePath makePath: /live_nodes/node3
   [junit4]   2> 1486168 T3045 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 1486169 T3051 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 1486169 T3049 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 1486169 T3047 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 1486168 T3039 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 1486169 T2941 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1486171 T3053 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@4328ec39 name:ZooKeeperConnection Watcher:127.0.0.1:47211/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1486171 T2941 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1486172 T2941 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 1486174 T2941 oascc.SolrZkClient.makePath makePath: /live_nodes/node4
   [junit4]   2> 1486177 T3045 oascc.ZkStateReader$3.process Updating live nodes... (5)
   [junit4]   2> 1486177 T3051 oascc.ZkStateReader$3.process Updating live nodes... (5)
   [junit4]   2> 1486177 T3049 oascc.ZkStateReader$3.process Updating live nodes... (5)
   [junit4]   2> 1486177 T3039 oascc.ZkStateReader$3.process Updating live nodes... (5)
   [junit4]   2> 1486177 T3047 oascc.ZkStateReader$3.process Updating live nodes... (5)
   [junit4]   2> 1486177 T3053 oascc.ZkStateReader$3.process Updating live nodes... (5)
   [junit4]   2> 1486178 T2941 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1486179 T3055 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@762ce41c name:ZooKeeperConnection Watcher:127.0.0.1:47211/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1486179 T2941 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1486181 T2941 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 1486182 T2941 oascc.SolrZkClient.makePath makePath: /live_nodes/node5
   [junit4]   2> 1486185 T3051 oascc.ZkStateReader$3.process Updating live nodes... (6)
   [junit4]   2> 1486185 T3053 oascc.ZkStateReader$3.process Updating live nodes... (6)
   [junit4]   2> 1486185 T3055 oascc.ZkStateReader$3.process Updating live nodes... (6)
   [junit4]   2> 1486185 T3039 oascc.ZkStateReader$3.process Updating live nodes... (6)
   [junit4]   2> 1486185 T3049 oascc.ZkStateReader$3.process Updating live nodes... (6)
   [junit4]   2> 1486185 T3047 oascc.ZkStateReader$3.process Updating live nodes... (6)
   [junit4]   2> 1486185 T3045 oascc.ZkStateReader$3.process Updating live nodes... (6)
   [junit4]   2> 1486186 T2941 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1486188 T3057 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@7c9ee047 name:ZooKeeperConnection Watcher:127.0.0.1:47211/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1486188 T2941 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1486189 T2941 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 1486191 T2941 oascc.SolrZkClient.makePath makePath: /live_nodes/node6
   [junit4]   2> 1486194 T3045 oascc.ZkStateReader$3.process Updating live nodes... (7)
   [junit4]   2> 1486194 T3047 oascc.ZkStateReader$3.process Updating live nodes... (7)
   [junit4]   2> 1486194 T3049 oascc.ZkStateReader$3.process Updating live nodes... (7)
   [junit4]   2> 1486194 T3039 oascc.ZkStateReader$3.process Updating live nodes... (7)
   [junit4]   2> 1486194 T3055 oascc.ZkStateReader$3.process Updating live nodes... (7)
   [junit4]   2> 1486194 T3053 oascc.ZkStateReader$3.process Updating live nodes... (7)
   [junit4]   2> 1486194 T3051 oascc.ZkStateReader$3.process Updating live nodes... (7)
   [junit4]   2> 1486194 T3057 oascc.ZkStateReader$3.process Updating live nodes... (7)
   [junit4]   2> 1486195 T2941 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1486196 T3059 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@2d26d80c name:ZooKeeperConnection Watcher:127.0.0.1:47211/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1486197 T2941 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1486198 T2941 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 1486200 T2941 oascc.SolrZkClient.makePath makePath: /live_nodes/node7
   [junit4]   2> 1486203 T3051 oascc.ZkStateReader$3.process Updating live nodes... (8)
   [junit4]   2> 1486203 T3047 oascc.ZkStateReader$3.process Updating live nodes... (8)
   [junit4]   2> 1486203 T3055 oascc.ZkStateReader$3.process Updating live nodes... (8)
   [junit4]   2> 1486203 T3053 oascc.ZkStateReader$3.process Updating live nodes... (8)
   [junit4]   2> 1486203 T3039 oascc.ZkStateReader$3.process Updating live nodes... (8)
   [junit4]   2> 1486203 T3049 oascc.ZkStateReader$3.process Updating live nodes... (8)
   [junit4]   2> 1486203 T3057 oascc.ZkStateReader$3.process Updating live nodes... (8)
   [junit4]   2> 1486203 T3059 oascc.ZkStateReader$3.process Updating live nodes... (8)
   [junit4]   2> 1486203 T3045 oascc.ZkStateReader$3.process Updating live nodes... (8)
   [junit4]   2> 1486204 T2941 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1486206 T3061 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1e06ee66 name:ZooKeeperConnection Watcher:127.0.0.1:47211/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1486206 T2941 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1486207 T2941 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 1486210 T2941 oascc.SolrZkClient.makePath makePath: /live_nodes/node8
   [junit4]   2> 1486213 T3045 oascc.ZkStateReader$3.process Updating live nodes... (9)
   [junit4]   2> 1486213 T3039 oascc.ZkStateReader$3.process Updating live nodes... (9)
   [junit4]   2> 1486213 T3061 oascc.ZkStateReader$3.process Updating live nodes... (9)
   [junit4]   2> 1486213 T3049 oascc.ZkStateReader$3.process Updating live nodes... (9)
   [junit4]   2> 1486213 T3055 oascc.ZkStateReader$3.process Updating live nodes... (9)
   [junit4]   2> 1486214 T2941 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1486213 T3059 oascc.ZkStateReader$3.process Updating live nodes... (9)
   [junit4]   2> 1486213 T3053 oascc.ZkStateReader$3.process Updating live nodes... (9)
   [junit4]   2> 1486213 T3047 oascc.ZkStateReader$3.process Updating live nodes... (9)
   [junit4]   2> 1486213 T3051 oascc.ZkStateReader$3.process Updating live nodes... (9)
   [junit4]   2> 1486213 T3057 oascc.ZkStateReader$3.process Updating live nodes... (9)
   [junit4]   2> 1486216 T3063 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@5eca88bc name:ZooKeeperConnection Watcher:127.0.0.1:47211/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1486216 T2941 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1486217 T2941 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 1486219 T2941 oascc.SolrZkClient.makePath makePath: /live_nodes/node9
   [junit4]   2> 1486223 T3051 oascc.ZkStateReader$3.process Updating live nodes... (10)
   [junit4]   2> 1486223 T3045 oascc.ZkStateReader$3.process Updating live nodes... (10)
   [junit4]   2> 1486224 T3049 oascc.ZkStateReader$3.process Updating live nodes... (10)
   [junit4]   2> 1486223 T3053 oascc.ZkStateReader$3.process Updating live nodes... (10)
   [junit4]   2> 1486223 T3061 oascc.ZkStateReader$3.process Updating live nodes... (10)
   [junit4]   2> 1486223 T3063 oascc.ZkStateReader$3.process Updating live nodes... (10)
   [junit4]   2> 1486223 T3057 oascc.ZkStateReader$3.process Updating live nodes... (10)
   [junit4]   2> 1486223 T3039 oascc.ZkStateReader$3.process Updating live nodes... (10)
   [junit4]   2> 1486223 T3059 oascc.ZkStateReader$3.process Updating live nodes... (10)
   [junit4]   2> 1486224 T2941 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1486224 T3047 oascc.ZkStateReader$3.process Updating live nodes... (10)
   [junit4]   2> 1486224 T3055 oascc.ZkStateReader$3.process Updating live nodes... (10)
   [junit4]   2> 1486226 T3065 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@600537b8 name:ZooKeeperConnection Watcher:127.0.0.1:47211/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1486227 T2941 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1486228 T2941 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 1486230 T2941 oascc.SolrZkClient.makePath makePath: /live_nodes/node10
   [junit4]   2> 1486232 T3051 oascc.ZkStateReader$3.process Updating live nodes... (11)
   [junit4]   2> 1486233 T3063 oascc.ZkStateReader$3.process Updating live nodes... (11)
   [junit4]   2> 1486233 T3045 oascc.ZkStateReader$3.process Updating live nodes... (11)
   [junit4]   2> 1486233 T3065 oascc.ZkStateReader$3.process Updating live nodes... (11)
   [junit4]   2> 1486233 T3039 oascc.ZkStateReader$3.process Updating live nodes... (11)
   [junit4]   2> 1486233 T3049 oascc.ZkStateReader$3.process Updating live nodes... (11)
   [junit4]   2> 1486233 T3053 oascc.ZkStateReader$3.process Updating live nodes... (11)
   [junit4]   2> 1486233 T3061 oascc.ZkStateReader$3.process Updating live nodes... (11)
   [junit4]   2> 1486233 T3047 oascc.ZkStateReader$3.process Updating live nodes... (11)
   [junit4]   2> 1486233 T3059 oascc.ZkStateReader$3.process Updating live nodes... (11)
   [junit4]   2> 1486233 T3057 oascc.ZkStateReader$3.process Updating live nodes... (11)
   [junit4]   2> 1486234 T2941 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1486234 T3055 oascc.ZkStateReader$3.process Updating live nodes... (11)
   [junit4]   2> 1486236 T3067 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@96650db name:ZooKeeperConnection Watcher:127.0.0.1:47211/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1486236 T2941 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1486237 T2941 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 1486240 T2941 oascc.SolrZkClient.makePath makePath: /live_nodes/node11
   [junit4]   2> 1486243 T3067 oascc.ZkStateReader$3.process Updating live nodes... (12)
   [junit4]   2> 1486243 T3045 oascc.ZkStateReader$3.process Updating live nodes... (12)
   [junit4]   2> 1486243 T3065 oascc.ZkStateReader$3.process Updating live nodes... (12)
   [junit4]   2> 1486244 T3061 oascc.ZkStateReader$3.process Updating live nodes... (12)
   [junit4]   2> 1486244 T3047 oascc.ZkStateReader$3.process Updating live nodes... (12)
   [junit4]   2> 1486243 T3039 oascc.ZkStateReader$3.process Updating live nodes... (12)
   [junit4]   2> 1486243 T3049 oascc.ZkStateReader$3.process Updating live nodes... (12)
   [junit4]   2> 1486243 T3051 oascc.ZkStateReader$3.process Updating live nodes... (12)
   [junit4]   2> 1486243 T3057 oascc.ZkStateReader$3.process Updating live nodes... (12)
   [junit4]   2> 1486243 T3059 oascc.ZkStateReader$3.process Updating live nodes... (12)
   [junit4]   2> 1486244 T2941 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1486244 T3055 oascc.ZkStateReader$3.process Updating live nodes... (12)
   [junit4]   2> 1486244 T3063 oascc.ZkStateReader$3.process Updating live nodes... (12)
   [junit4]   2> 1486244 T3053 oascc.ZkStateReader$3.process Updating live nodes... (12)
   [junit4]   2> 1486246 T3069 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@272d69d7 name:ZooKeeperConnection Watcher:127.0.0.1:47211/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1486247 T2941 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1486248 T2941 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 1486250 T2941 oascc.SolrZkClient.makePath makePath: /live_nodes/node12
   [junit4]   2> 1486253 T3039 oascc.ZkStateReader$3.process Updating live nodes... (13)
   [junit4]   2> 1486254 T3061 oascc.ZkStateReader$3.process Updating live nodes... (13)
   [junit4]   2> 1486254 T3055 oascc.ZkStateReader$3.process Updating live nodes... (13)
   [junit4]   2> 1486254 T3059 oascc.ZkStateReader$3.process Updating live nodes... (13)
   [junit4]   2> 1486254 T3069 oascc.ZkStateReader$3.process Updating live nodes... (13)
   [junit4]   2> 1486254 T3057 oascc.ZkStateReader$3.process Updating live nodes... (13)
   [junit4]   2> 1486254 T3063 oascc.ZkStateReader$3.process Updating live nodes... (13)
   [junit4]   2> 1486254 T3051 oascc.ZkStateReader$3.process Updating live nodes... (13)
   [junit4]   2> 1486254 T3049 oascc.ZkStateReader$3.process Updating live nodes... (13)
   [junit4]   2> 1486254 T3065 oascc.ZkStateReader$3.process Updating live nodes... (13)
   [junit4]   2> 1486254 T3067 oascc.ZkStateReader$3.process Updating live nodes... (13)
   [junit4]   2> 1486253 T3045 oascc.ZkStateReader$3.process Updating live nodes... (13)
   [junit4]   2> 1486253 T3053 oascc.ZkStateReader$3.process Updating live nodes... (13)
   [junit4]   2> 1486253 T3047 oascc.ZkStateReader$3.process Updating live nodes... (13)
   [junit4]   2> 1486255 T2941 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1486257 T3071 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@3df56cfc name:ZooKeeperConnection Watcher:127.0.0.1:47211/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1486257 T2941 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1486259 T2941 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 1486261 T2941 oascc.SolrZkClient.makePath makePath: /live_nodes/node13
   [junit4]   2> 1486264 T3069 oascc.ZkStateReader$3.process Updating live nodes... (14)
   [junit4]   2> 1486264 T3065 oascc.ZkStateReader$3.process Updating live nodes... (14)
   [junit4]   2> 1486265 T3061 oascc.ZkStateReader$3.process Updating live nodes... (14)
   [junit4]   2> 1486265 T3067 oascc.ZkStateReader$3.process Updating live nodes... (14)
   [junit4]   2> 1486264 T3049 oascc.ZkStateReader$3.process Updating live nodes... (14)
   [junit4]   2> 1486264 T3063 oascc.ZkStateReader$3.process Updating live nodes... (14)
   [junit4]   2> 1486264 T3045 oascc.ZkStateReader$3.process Updating live nodes... (14)
   [junit4]   2> 1486264 T3051 oascc.ZkStateReader$3.process Updating live nodes... (14)
   [junit4]   2> 1486266 T2941 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1486265 T3053 oascc.ZkStateReader$3.process Updating live nodes... (14)
   [junit4]   2> 1486265 T3055 oascc.ZkStateReader$3.process Updating live nodes... (14)
   [junit4]   2> 1486265 T3057 oascc.ZkStateReader$3.process Updating live nodes... (14)
   [junit4]   2> 1486265 T3059 oascc.ZkStateReader$3.process Updating live nodes... (14)
   [junit4]   2> 1486267 T3073 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@5046497b name:ZooKeeperConnection Watcher:127.0.0.1:47211/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1486265 T3039 oascc.ZkStateReader$3.process Updating live nodes... (14)
   [junit4]   2> 1486265 T3071 oascc.ZkStateReader$3.process Updating live nodes... (14)
   [junit4]   2> 1486265 T3047 oascc.ZkStateReader$3.process Updating live nodes... (14)
   [junit4]   2> 1486268 T2941 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1486269 T2941 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 1486271 T2941 oascc.SolrZkClient.makePath makePath: /live_nodes/node14
   [junit4]   2> 1486274 T3047 oascc.ZkStateReader$3.process Updating live nodes... (15)
   [junit4]   2> 1486275 T3053 oascc.ZkStateReader$3.process Updating live nodes... (15)
   [junit4]   2> 1486276 T3055 oascc.ZkStateReader$3.process Updating live nodes... (15)
   [junit4]   2> 1486276 T3059 oascc.ZkStateReader$3.process Updating live nodes... (15)
   [junit4]   2> 1486276 T3045 oascc.ZkStateReader$3.process Updating live nodes... (15)
   [junit4]   2> 1486275 T3063 oascc.ZkStateReader$3.process Updating live nodes... (15)
   [junit4]   2> 1486277 T2941 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1486275 T3061 oascc.ZkStateReader$3.process Updating live nodes... (15)
   [junit4]   2> 1486275 T3051 oascc.ZkStateReader$3.process Updating live nodes... (15)
   [junit4]   2> 1486275 T3039 oascc.ZkStateReader$3.process Updating live nodes... (15)
   [junit4]   2> 1486275 T3069 oascc.ZkStateReader$3.process Updating live nodes... (15)
   [junit4]   2> 1486275 T3071 oascc.ZkStateReader$3.process Updating live nodes... (15)
   [junit4]   2> 1486278 T3075 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@19bcfea name:ZooKeeperConnection Watcher:127.0.0.1:47211/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1486276 T3073 oascc.ZkStateReader$3.process Updating live nodes... (15)
   [junit4]   2> 1486276 T3067 oascc.ZkStateReader$3.process Updating live nodes... (15)
   [junit4]   2> 1486276 T3049 oascc.ZkStateReader$3.process Updating live nodes... (15)
   [junit4]   2> 1486276 T3057 oascc.ZkStateReader$3.process Updating live nodes... (15)
   [junit4]   2> 1486276 T3065 oascc.ZkStateReader$3.process Updating live nodes... (15)
   [junit4]   2> 1486279 T2941 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1486281 T2941 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 1486283 T2941 oascc.SolrZkClient.makePath makePath: /live_nodes/node15
   [junit4]   2> 1486286 T3045 oascc.ZkStateReader$3.process Updating live nodes... (16)
   [junit4]   2> 1486287 T3047 oascc.ZkStateReader$3.process Updating live nodes... (16)
   [junit4]   2> 1486287 T3055 oascc.ZkStateReader$3.process Updating live nodes... (16)
   [junit4]   2> 1486288 T3057 oascc.ZkStateReader$3.process Updating live nodes... (16)
   [junit4]   2> 1486288 T3073 oascc.ZkStateReader$3.process Updating live nodes... (16)
   [junit4]   2> 1486288 T3059 oascc.ZkStateReader$3.process Updating live nodes... (16)
   [junit4]   2> 1486288 T2941 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1486288 T3071 oascc.ZkStateReader$3.process Updating live nodes... (16)
   [junit4]   2> 1486288 T3067 oascc.ZkStateReader$3.process Updating live nodes... (16)
   [junit4]   2> 1486287 T3039 oascc.ZkStateReader$3.process Updating live nodes... (16)
   [junit4]   2> 1486287 T3065 oascc.ZkStateReader$3.process Updating live nodes... (16)
   [junit4]   2> 1486287 T3063 oascc.ZkStateReader$3.process Updating live nodes... (16)
   [junit4]   2> 1486287 T3069 oascc.ZkStateReader$3.process Updating live nodes... (16)
   [junit4]   2> 1486287 T3051 oascc.ZkStateReader$3.process Updating live nodes... (16)
   [junit4]   2> 1486287 T3053 oascc.ZkStateReader$3.process Updating live nodes... (16)
   [junit4]   2> 1486287 T3075 oascc.ZkStateReader$3.process Updating live nodes... (16)
   [junit4]   2> 1486287 T3049 oascc.ZkStateReader$3.process Updating live nodes... (16)
   [junit4]   2> 1486287 T3061 oascc.ZkStateReader$3.process Updating live nodes... (16)
   [junit4]   2> 1486290 T3077 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@557e641c name:ZooKeeperConnection Watcher:127.0.0.1:47211/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1486292 T2941 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1486293 T2941 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 1486295 T2941 oascc.SolrZkClient.makePath makePath: /live_nodes/node16
   [junit4]   2> 1486298 T3045 oascc.ZkStateReader$3.process Updating live nodes... (17)
   [junit4]   2> 1486298 T3047 oascc.ZkStateReader$3.process Updating live nodes... (17)
   [junit4]   2> 1486298 T3071 oascc.ZkStateReader$3.process Updating live nodes... (17)
   [junit4]   2> 1486299 T3039 oascc.ZkStateReader$3.process Updating live nodes... (17)
   [junit4]   2> 1486299 T3057 oascc.ZkStateReader$3.process Updating live nodes... (17)
   [junit4]   2> 1486300 T3075 oascc.ZkStateReader$3.process Updating live nodes... (17)
   [junit4]   2> 1486299 T3073 oascc.ZkStateReader$3.process Updating live nodes... (17)
   [junit4]   2> 1486299 T3059 oascc.ZkStateReader$3.process Updating live nodes... (17)
   [junit4]   2> 1486300 T3055 oascc.ZkStateReader$3.process Updating live nodes... (17)
   [junit4]   2> 1486300 T3049 oascc.ZkStateReader$3.process Updating live nodes... (17)
   [junit4]   2> 1486300 T3077 oascc.ZkStateReader$3.process Updating live nodes... (17)
   [junit4]   2> 1486300 T3053 oascc.ZkStateReader$3.process Updating live nodes... (17)
   [junit4]   2> 1486300 T3069 oascc.ZkStateReader$3.process Updating live nodes... (17)
   [junit4]   2> 1486299 T3065 oascc.ZkStateReader$3.process Updating live nodes... (17)
   [junit4]   2> 1486299 T3051 oascc.ZkStateReader$3.process Updating live nodes... (17)
   [junit4]   2> 1486299 

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

xecutor.retryOperation(ZkCmdExecutor.java:73)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient.getChildren(SolrZkClient.java:253)
   [junit4]   2> 	at org.apache.solr.common.cloud.ZkStateReader.updateClusterState(ZkStateReader.java:388)
   [junit4]   2> 	at org.apache.solr.common.cloud.ZkStateReader.updateClusterState(ZkStateReader.java:214)
   [junit4]   2> 	at org.apache.solr.cloud.Overseer$ClusterStateUpdater.run(Overseer.java:180)
   [junit4]   2> 	at java.lang.Thread.run(Thread.java:679)
   [junit4]   2> 
   [junit4]   2> 1503362 T2941 oas.SolrTestCaseJ4.tearDown ###Ending testShardLeaderChange
   [junit4]   1> client port:0.0.0.0/0.0.0.0:0
   [junit4]   2> 1503364 T2941 oas.SolrTestCaseJ4.initCore ####initCore
   [junit4]   2> 1503365 T2941 oas.SolrTestCaseJ4.initCore ####initCore end
   [junit4]   2> 1503597 T3431 oasc.LeaderElector$1.process WARN  org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /collections/collection1/leader_elect/shard1/election
   [junit4]   2> 	at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
   [junit4]   2> 	at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
   [junit4]   2> 	at org.apache.zookeeper.ZooKeeper.getChildren(ZooKeeper.java:1468)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:256)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:253)
   [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:253)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:93)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector.access$000(LeaderElector.java:55)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector$1.process(LeaderElector.java:138)
   [junit4]   2> 	at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:519)
   [junit4]   2> 	at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:495)
   [junit4]   2> 
   [junit4]   2> 1503597 T3431 oasc.LeaderElector$1.process WARN  org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /collections/collection1/leader_elect/shard1/election
   [junit4]   2> 	at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
   [junit4]   2> 	at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
   [junit4]   2> 	at org.apache.zookeeper.ZooKeeper.getChildren(ZooKeeper.java:1468)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:256)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:253)
   [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:253)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:93)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector.access$000(LeaderElector.java:55)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector$1.process(LeaderElector.java:138)
   [junit4]   2> 	at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:519)
   [junit4]   2> 	at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:495)
   [junit4]   2> 
   [junit4]   2> 1504424 T3439 oasc.LeaderElector$1.process WARN  org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /collections/collection1/leader_elect/shard1/election
   [junit4]   2> 	at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
   [junit4]   2> 	at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
   [junit4]   2> 	at org.apache.zookeeper.ZooKeeper.getChildren(ZooKeeper.java:1468)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:256)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:253)
   [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:253)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:93)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector.access$000(LeaderElector.java:55)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector$1.process(LeaderElector.java:138)
   [junit4]   2> 	at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:519)
   [junit4]   2> 	at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:495)
   [junit4]   2> 
   [junit4]   2> 1504424 T3439 oasc.LeaderElector$1.process WARN  org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /collections/collection1/leader_elect/shard1/election
   [junit4]   2> 	at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
   [junit4]   2> 	at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
   [junit4]   2> 	at org.apache.zookeeper.ZooKeeper.getChildren(ZooKeeper.java:1468)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:256)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:253)
   [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:253)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:93)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector.access$000(LeaderElector.java:55)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector$1.process(LeaderElector.java:138)
   [junit4]   2> 	at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:519)
   [junit4]   2> 	at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:495)
   [junit4]   2> 
   [junit4]   2> 1506366 T2941 oas.SolrTestCaseJ4.deleteCore ###deleteCore
   [junit4]   2> NOTE: test params are: codec=Lucene46: {}, docValues:{}, sim=DefaultSimilarity, locale=es_PR, timezone=Atlantic/Reykjavik
   [junit4]   2> NOTE: FreeBSD 9.1-RELEASE-p3 amd64/Sun Microsystems Inc. 1.6.0_32 (64-bit)/cpus=16,threads=1,free=149006352,total=401473536
   [junit4]   2> NOTE: All tests run in this JVM: [SynonymTokenizerTest, ClusterStateUpdateTest, TestShardHandlerFactory, OverseerCollectionProcessorTest, AnalysisAfterCoreReloadTest, SolrInfoMBeanTest, ResponseLogComponentTest, TestSort, PolyFieldTest, TestReloadAndDeleteDocs, UUIDFieldTest, TestManagedSchema, CopyFieldTest, UnloadDistributedZkTest, DistributedSpellCheckComponentTest, TestHighFrequencyDictionaryFactory, TestDocBasedVersionConstraints, TestRandomMergePolicy, HdfsUnloadDistributedZkTest, TestPHPSerializedResponseWriter, TestBadConfig, LeaderElectionTest, IndexSchemaTest, SliceStateUpdateTest, TestSolrXmlPersistor, ZkCLITest, TestSerializedLuceneMatchVersion, TestPseudoReturnFields, TestRemoteStreaming, TestSchemaSimilarityResource, UpdateParamsTest, TestDynamicFieldResource, QueryElevationComponentTest, MBeansHandlerTest, TestLMDirichletSimilarityFactory, SpellPossibilityIteratorTest, TestRecoveryHdfs, DocumentBuilderTest, SyncSliceTest, BadComponentTest, TestDocumentBuilder, TermsComponentTest, SimpleFacetsTest, TestConfig, TestFileDictionaryLookup, TestLFUCache, TestRealTimeGet, SolrCoreTest, TestGroupingSearch, DateMathParserTest, TestSolrDeletionPolicy1, WordBreakSolrSpellCheckerTest, SpatialFilterTest, TermVectorComponentTest, TestDocSet, ShowFileRequestHandlerTest, DOMUtilTest, ChangedSchemaMergeTest, SliceStateTest, HdfsDirectoryTest, SampleTest, FieldMutatingUpdateProcessorTest, TestMergePolicyConfig, SOLR749Test, TestReplicationHandler, ReturnFieldsTest, TestFunctionQuery, PrimitiveFieldTypeTest, EchoParamsTest, TestSurroundQueryParser, TestStressUserVersions, InfoHandlerTest, TriLevelCompositeIdRoutingTest, SuggesterTest, LoggingHandlerTest, PeerSyncTest, TestCollationFieldDocValues, SuggesterFSTTest, TestLRUCache, QueryResultKeyTest, ResourceLoaderTest, TestPostingsSolrHighlighter, ScriptEngineTest, OverseerTest]
   [junit4] Completed on J0 in 27.78s, 8 tests, 1 error <<< FAILURES!

[...truncated 531 lines...]
BUILD FAILED
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/build.xml:459: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/build.xml:439: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/build.xml:39: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/extra-targets.xml:37: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build.xml:189: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/common-build.xml:491: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/lucene/common-build.xml:1307: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/lucene/common-build.xml:940: There were test failures: 348 suites, 1522 tests, 1 error, 35 ignored (6 assumptions)

Total time: 60 minutes 47 seconds
Build step 'Invoke Ant' marked build as failure
Archiving artifacts
Recording test results
Email was triggered for: Failure
Sending email for trigger: Failure