lucene-dev mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From Policeman Jenkins Server <jenk...@thetaphi.de>
Subject [JENKINS] Lucene-Solr-trunk-Linux (32bit/jdk1.7.0_51) - Build # 9704 - Still Failing!
Date Fri, 07 Mar 2014 11:37:32 GMT
Build: http://jenkins.thetaphi.de/job/Lucene-Solr-trunk-Linux/9704/
Java: 32bit/jdk1.7.0_51 -client -XX:+UseParallelGC

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

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

Stack Trace:
org.apache.solr.common.SolrException: Could not register as the leader because creating the ephemeral registration node in ZooKeeper failed
	at __randomizedtesting.SeedInfo.seed([EC6FA60BD0AF2C0F:E86729F8C20AC32E]:0)
	at org.apache.solr.cloud.ShardLeaderElectionContextBase.runLeaderProcess(ElectionContext.java:135)
	at org.apache.solr.cloud.LeaderElector.runIamLeaderProcess(LeaderElector.java:164)
	at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:108)
	at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:156)
	at org.apache.solr.cloud.LeaderElector.joinElection(LeaderElector.java:289)
	at org.apache.solr.cloud.OverseerTest$MockZKController.publishState(OverseerTest.java:155)
	at org.apache.solr.cloud.OverseerTest.testOverseerFailure(OverseerTest.java:666)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:606)
	at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java: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:744)
Caused by: org.apache.zookeeper.KeeperException$NodeExistsException: KeeperErrorCode = NodeExists for /collections/collection1/leaders/shard1
	at org.apache.zookeeper.KeeperException.create(KeeperException.java:119)
	at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
	at org.apache.zookeeper.ZooKeeper.create(ZooKeeper.java:783)
	at org.apache.solr.common.cloud.SolrZkClient$10.execute(SolrZkClient.java:431)
	at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
	at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:428)
	at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:385)
	at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:372)
	at org.apache.solr.cloud.ShardLeaderElectionContextBase$1.execute(ElectionContext.java:127)
	at org.apache.solr.common.util.RetryUtil.retryOnThrowable(RetryUtil.java:31)
	at org.apache.solr.cloud.ShardLeaderElectionContextBase.runLeaderProcess(ElectionContext.java:122)
	... 46 more




Build Log:
[...truncated 10654 lines...]
   [junit4] Suite: org.apache.solr.cloud.OverseerTest
   [junit4]   2> 700083 T2589 oas.SolrTestCaseJ4.buildSSLConfig Randomized ssl (true) and clientAuth (true)
   [junit4]   2> 700083 T2589 oas.SolrTestCaseJ4.initCore ####initCore
   [junit4]   2> Creating dataDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solrtest-OverseerTest-1394191440697
   [junit4]   2> 700084 T2589 oas.SolrTestCaseJ4.initCore ####initCore end
   [junit4]   2> 700086 T2589 oas.SolrTestCaseJ4.setUp ###Starting testOverseerFailure
   [junit4]   2> 700087 T2589 oasc.ZkTestServer.run STARTING ZK TEST SERVER
   [junit4]   2> 700087 T2590 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
   [junit4]   2> 700187 T2589 oasc.ZkTestServer.run start zk server on port:34566
   [junit4]   2> 700188 T2589 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 700240 T2596 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1bc26a9 name:ZooKeeperConnection Watcher:127.0.0.1:34566 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 700240 T2589 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 700243 T2589 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 700244 T2598 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@d18425 name:ZooKeeperConnection Watcher:127.0.0.1:34566 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 700244 T2589 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 700245 T2589 oascc.SolrZkClient.makePath makePath: /solr
   [junit4]   2> 700248 T2589 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 700248 T2600 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@616781 name:ZooKeeperConnection Watcher:127.0.0.1:34566/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 700249 T2589 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 700249 T2589 oascc.SolrZkClient.makePath makePath: /live_nodes
   [junit4]   2> 700250 T2589 oascc.SolrZkClient.makePath makePath: /clusterstate.json
   [junit4]   2> 700252 T2589 oascc.SolrZkClient.makePath makePath: /aliases.json
   [junit4]   2> 700253 T2589 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 700255 T2589 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 700256 T2602 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@a3ca4d name:ZooKeeperConnection Watcher:127.0.0.1:34566/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 700256 T2589 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 700257 T2589 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 700258 T2589 oascc.SolrZkClient.makePath makePath: /live_nodes/node1
   [junit4]   2> 700260 T2602 oascc.ZkStateReader$3.process Updating live nodes... (1)
   [junit4]   2> 700260 T2600 oascc.ZkStateReader$3.process Updating live nodes... (1)
   [junit4]   2> 700260 T2589 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 700261 T2604 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1bd524d name:ZooKeeperConnection Watcher:127.0.0.1:34566/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 700261 T2589 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 700262 T2589 oascc.SolrZkClient.makePath makePath: /overseer_elect
   [junit4]   2> 700263 T2589 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
   [junit4]   2> 700266 T2589 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:34566_solr
   [junit4]   2> 700266 T2589 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
   [junit4]   2> 700267 T2589 oasc.Overseer.start Overseer (id=91369730257846276-127.0.0.1:34566_solr-n_0000000000) starting
   [junit4]   2> 700270 T2589 oascc.SolrZkClient.makePath makePath: /overseer/queue
   [junit4]   2> 700273 T2589 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
   [junit4]   2> 700276 T2589 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
   [junit4]   2> 700277 T2606 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
   [junit4]   2> 700278 T2606 oasc.OverseerCollectionProcessor.prioritizeOverseerNodes prioritizing overseer nodes
   [junit4]   2> 700278 T2605 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
   [junit4]   2> 701279 T2604 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 701281 T2605 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 701281 T2605 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> 701281 T2605 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1]
   [junit4]   2> 701282 T2605 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
   [junit4]   2> 701283 T2604 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 701284 T2600 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> 701284 T2602 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> 701780 T2589 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
   [junit4]   2> 701789 T2589 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 701793 T2604 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 701794 T2589 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 701795 T2605 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 701797 T2604 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 701797 T2589 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
   [junit4]   2> 701798 T2605 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> 701798 T2605 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
   [junit4]   2> 701801 T2604 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 701903 T2600 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> 701903 T2602 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> 702957 T2589 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
   [junit4]   2> 702962 T2589 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 702962 T2608 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@486919 name:ZooKeeperConnection Watcher:127.0.0.1:34566/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 702963 T2589 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 702965 T2589 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:34566_solr
   [junit4]   2> 702966 T2589 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
   [junit4]   2> 702967 T2589 oasc.Overseer.start Overseer (id=91369730257846277-127.0.0.1:34566_solr-n_0000000001) starting
   [junit4]   2> 702971 T2610 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
   [junit4]   2> 702971 T2610 oasc.OverseerCollectionProcessor.prioritizeOverseerNodes prioritizing overseer nodes
   [junit4]   2> 702971 T2609 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
   [junit4]   2> 702973 T2609 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 702974 T2609 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> 702974 T2609 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
   [junit4]   2> 702976 T2608 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 702977 T2600 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> 702977 T2602 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> 703031 T2608 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 703031 T2589 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
   [junit4]   2> 703032 T2609 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 703037 T2602 oasc.LeaderElector.checkIfIamLeader WARN Our node is no longer in line to be leader
   [junit4]   2> 703037 T2589 oasc.LeaderElector.checkIfIamLeader WARN Failed setting watch org.apache.zookeeper.KeeperException$NoNodeException: KeeperErrorCode = NoNode for /collections/collection1/leader_elect/shard1/election/91369730257846275-node1_core1-n_0000000000
   [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:276)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:273)
   [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:273)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:125)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector.joinElection(LeaderElector.java:289)
   [junit4]   2> 	at org.apache.solr.cloud.OverseerTest$MockZKController.publishState(OverseerTest.java:155)
   [junit4]   2> 	at org.apache.solr.cloud.OverseerTest.testOverseerFailure(OverseerTest.java:666)
   [junit4]   2> 	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
   [junit4]   2> 	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
   [junit4]   2> 	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
   [junit4]   2> 	at java.lang.reflect.Method.invoke(Method.java:606)
   [junit4]   2> 	at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java: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:744)
   [junit4]   2> 
   [junit4]   2> 703038 T2602 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 703038 T2609 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:176)
   [junit4]   2> 		at org.apache.solr.common.cloud.SolrZkClient$2.execute(SolrZkClient.java:173)
   [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:173)
   [junit4]   2> 		at org.apache.solr.common.cloud.SolrZkClient.clean(SolrZkClient.java:635)
   [junit4]   2> 		at org.apache.solr.common.cloud.SolrZkClient.clean(SolrZkClient.java:630)
   [junit4]   2> 		at org.apache.solr.common.cloud.SolrZkClient.clean(SolrZkClient.java:630)
   [junit4]   2> 		at org.apache.solr.common.cloud.SolrZkClient.clean(SolrZkClient.java:630)
   [junit4]   2> 		at org.apache.solr.cloud.Overseer$ClusterStateUpdater.removeCore(Overseer.java:976)
   [junit4]   2> 		at org.apache.solr.cloud.Overseer$ClusterStateUpdater.processMessage(Overseer.java:253)
   [junit4]   2> 		at org.apache.solr.cloud.Overseer$ClusterStateUpdater.run(Overseer.java:202)
   [junit4]   2> 		at java.lang.Thread.run(Thread.java:744)
   [junit4]   2> 	
   [junit4]   2> 703039 T2589 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 703041 T2608 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 703043 T2608 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 703043 T2609 oasc.Overseer$ClusterStateUpdater.setShardLeader ERROR Could not mark shard leader for non existing collection:collection1
   [junit4]   2> 703045 T2608 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 703147 T2600 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> 703147 T2602 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> 704042 T2589 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 705046 T2589 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 706049 T2589 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 707052 T2589 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 708056 T2589 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 709059 T2589 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 710062 T2589 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 711064 T2589 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 712067 T2589 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 713078 T2589 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 714083 T2589 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 715087 T2589 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 716090 T2589 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 717094 T2589 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 718097 T2589 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 718105 T2600 oascc.ZkStateReader$3.process Updating live nodes... (0)
   [junit4]   2> 718109 T2589 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:34566 34566
   [junit4]   2> 718345 T2589 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=EC6FA60BD0AF2C0F -Dtests.multiplier=3 -Dtests.slow=true -Dtests.locale=ko_KR -Dtests.timezone=Mideast/Riyadh89 -Dtests.file.encoding=ISO-8859-1
   [junit4] ERROR   18.3s J1 | OverseerTest.testOverseerFailure <<<
   [junit4]    > Throwable #1: org.apache.solr.common.SolrException: Could not register as the leader because creating the ephemeral registration node in ZooKeeper failed
   [junit4]    > 	at __randomizedtesting.SeedInfo.seed([EC6FA60BD0AF2C0F:E86729F8C20AC32E]:0)
   [junit4]    > 	at org.apache.solr.cloud.ShardLeaderElectionContextBase.runLeaderProcess(ElectionContext.java:135)
   [junit4]    > 	at org.apache.solr.cloud.LeaderElector.runIamLeaderProcess(LeaderElector.java:164)
   [junit4]    > 	at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:108)
   [junit4]    > 	at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:156)
   [junit4]    > 	at org.apache.solr.cloud.LeaderElector.joinElection(LeaderElector.java:289)
   [junit4]    > 	at org.apache.solr.cloud.OverseerTest$MockZKController.publishState(OverseerTest.java:155)
   [junit4]    > 	at org.apache.solr.cloud.OverseerTest.testOverseerFailure(OverseerTest.java:666)
   [junit4]    > 	at java.lang.Thread.run(Thread.java:744)
   [junit4]    > Caused by: org.apache.zookeeper.KeeperException$NodeExistsException: KeeperErrorCode = NodeExists for /collections/collection1/leaders/shard1
   [junit4]    > 	at org.apache.zookeeper.KeeperException.create(KeeperException.java:119)
   [junit4]    > 	at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
   [junit4]    > 	at org.apache.zookeeper.ZooKeeper.create(ZooKeeper.java:783)
   [junit4]    > 	at org.apache.solr.common.cloud.SolrZkClient$10.execute(SolrZkClient.java:431)
   [junit4]    > 	at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
   [junit4]    > 	at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:428)
   [junit4]    > 	at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:385)
   [junit4]    > 	at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:372)
   [junit4]    > 	at org.apache.solr.cloud.ShardLeaderElectionContextBase$1.execute(ElectionContext.java:127)
   [junit4]    > 	at org.apache.solr.common.util.RetryUtil.retryOnThrowable(RetryUtil.java:31)
   [junit4]    > 	at org.apache.solr.cloud.ShardLeaderElectionContextBase.runLeaderProcess(ElectionContext.java:122)
   [junit4]    > 	... 46 more
   [junit4]   2> 718364 T2589 oas.SolrTestCaseJ4.setUp ###Starting testBadQueueItem
   [junit4]   2> 718364 T2589 oasc.ZkTestServer.run STARTING ZK TEST SERVER
   [junit4]   2> 718365 T2611 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
   [junit4]   2> 718465 T2589 oasc.ZkTestServer.run start zk server on port:41659
   [junit4]   2> 718466 T2589 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 718468 T2617 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1bd336b name:ZooKeeperConnection Watcher:127.0.0.1:41659 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 718469 T2589 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 718486 T2589 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 718487 T2619 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@ecde5a name:ZooKeeperConnection Watcher:127.0.0.1:41659 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 718487 T2589 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 718487 T2589 oascc.SolrZkClient.makePath makePath: /solr
   [junit4]   2> 718489 T2589 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 718490 T2621 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1f488fb name:ZooKeeperConnection Watcher:127.0.0.1:41659/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 718491 T2589 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 718491 T2589 oascc.SolrZkClient.makePath makePath: /live_nodes
   [junit4]   2> 718492 T2589 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 718493 T2623 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@138ead8 name:ZooKeeperConnection Watcher:127.0.0.1:41659/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 718493 T2589 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 718494 T2589 oascc.SolrZkClient.makePath makePath: /overseer_elect
   [junit4]   2> 718495 T2589 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
   [junit4]   2> 718498 T2589 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:41659_solr
   [junit4]   2> 718498 T2589 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
   [junit4]   2> 718500 T2589 oasc.Overseer.start Overseer (id=91369731455844355-127.0.0.1:41659_solr-n_0000000000) starting
   [junit4]   2> 718501 T2589 oascc.SolrZkClient.makePath makePath: /overseer/queue
   [junit4]   2> 718503 T2589 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
   [junit4]   2> 718505 T2589 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
   [junit4]   2> 718507 T2625 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
   [junit4]   2> 718507 T2589 oascc.SolrZkClient.makePath makePath: /clusterstate.json
   [junit4]   2> 718507 T2625 oasc.OverseerCollectionProcessor.prioritizeOverseerNodes prioritizing overseer nodes
   [junit4]   2> 718507 T2624 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
   [junit4]   2> 718509 T2589 oascc.SolrZkClient.makePath makePath: /aliases.json
   [junit4]   2> 718512 T2589 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 718516 T2589 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 718517 T2627 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@829004 name:ZooKeeperConnection Watcher:127.0.0.1:41659/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 718517 T2589 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 718519 T2589 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 718521 T2589 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1
   [junit4]   2> 718523 T2621 oascc.ZkStateReader$3.process Updating live nodes... (1)
   [junit4]   2> 718523 T2627 oascc.ZkStateReader$3.process Updating live nodes... (1)
   [junit4]   2> 718524 T2623 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 718525 T2624 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 718525 T2624 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"active",
   [junit4]   2> 	  "node_name":"127.0.0.1",
   [junit4]   2> 	  "core":"core1",
   [junit4]   2> 	  "core_node_name":"node1",
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "numShards":"3",
   [junit4]   2> 	  "base_url":"http://127.0.0.1/solr/"}
   [junit4]   2> 718526 T2624 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1, shard2, shard3]
   [junit4]   2> 718526 T2624 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard3
   [junit4]   2> 718527 T2623 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 718528 T2621 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> 718528 T2627 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> 719024 T2589 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard3/election
   [junit4]   2> 719033 T2589 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard3
   [junit4]   2> 719037 T2623 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 719039 T2623 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 719039 T2624 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 719042 T2624 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"active",
   [junit4]   2> 	  "node_name":"127.0.0.1",
   [junit4]   2> 	  "core":"core2",
   [junit4]   2> 	  "core_node_name":"node2",
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "numShards":"3",
   [junit4]   2> 	  "base_url":"http://127.0.0.1/solr/"}
   [junit4]   2> 719042 T2624 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
   [junit4]   2> 719042 T2624 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard2
   [junit4]   2> 719044 T2623 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 719147 T2621 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> 719148 T2627 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> 719539 T2589 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard2/election
   [junit4]   2> 719545 T2589 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard2
   [junit4]   2> 719548 T2623 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 719549 T2623 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 719549 T2623 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 719551 T2624 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 719552 T2623 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 719555 T2624 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"active",
   [junit4]   2> 	  "node_name":"127.0.0.1",
   [junit4]   2> 	  "core":"core3",
   [junit4]   2> 	  "core_node_name":"node3",
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "numShards":"3",
   [junit4]   2> 	  "base_url":"http://127.0.0.1/solr/"}
   [junit4]   2> 719556 T2624 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
   [junit4]   2> 719556 T2624 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
   [junit4]   2> 719558 T2623 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 719603 T2602 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
   [junit4]   2> 719660 T2627 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> 719660 T2621 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> 720052 T2589 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
   [junit4]   2> 720058 T2589 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 720062 T2623 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 720062 T2623 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 720063 T2623 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 720063 T2624 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 720066 T2623 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 720169 T2621 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> 720169 T2627 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> 720214 T2623 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 720215 T2623 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 720215 T2623 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 720216 T2623 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 720217 T2624 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 720217 T2624 oasc.Overseer$ClusterStateUpdater.checkKeyExistence ERROR Skipping invalid Overseer message because it has no collection specified: {
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"active",
   [junit4]   2> 	  "node_name":"127.0.0.1",
   [junit4]   2> 	  "core":"core0",
   [junit4]   2> 	  "core_node_name":"node0",
   [junit4]   2> 	  "collection":"",
   [junit4]   2> 	  "numShards":"1",
   [junit4]   2> 	  "base_url":"http://127.0.0.1/solr/"}
   [junit4]   2> 720220 T2624 oasc.Overseer$ClusterStateUpdater.checkKeyExistence ERROR Skipping invalid Overseer message because it has no collection specified: {
   [junit4]   2> 	  "operation":"deletecore",
   [junit4]   2> 	  "node_name":"127.0.0.1",
   [junit4]   2> 	  "core":"core0",
   [junit4]   2> 	  "core_node_name":"node0",
   [junit4]   2> 	  "collection":""}
   [junit4]   2> 720222 T2623 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 720223 T2624 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"active",
   [junit4]   2> 	  "node_name":"127.0.0.1",
   [junit4]   2> 	  "core":"core1",
   [junit4]   2> 	  "core_node_name":"node1",
   [junit4]   2> 	  "collection":"collection2",
   [junit4]   2> 	  "numShards":"3",
   [junit4]   2> 	  "base_url":"http://127.0.0.1/solr/"}
   [junit4]   2> 720223 T2624 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection2 with shards [shard1, shard2, shard3]
   [junit4]   2> 720223 T2624 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard3
   [junit4]   2> 720225 T2623 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 720327 T2621 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> 720327 T2627 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> 720718 T2589 oascc.SolrZkClient.makePath makePath: /collections/collection2/leader_elect/shard3/election
   [junit4]   2> 720734 T2589 oascc.SolrZkClient.makePath makePath: /collections/collection2/leaders/shard3
   [junit4]   2> 720747 T2623 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 720747 T2623 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 720748 T2623 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 720750 T2623 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 720750 T2624 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 720754 T2624 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"active",
   [junit4]   2> 	  "node_name":"127.0.0.1",
   [junit4]   2> 	  "core":"core2",
   [junit4]   2> 	  "core_node_name":"node2",
   [junit4]   2> 	  "collection":"collection2",
   [junit4]   2> 	  "numShards":"3",
   [junit4]   2> 	  "base_url":"http://127.0.0.1/solr/"}
   [junit4]   2> 720755 T2624 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
   [junit4]   2> 720755 T2624 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard2
   [junit4]   2> 720764 T2623 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 720866 T2627 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> 720866 T2621 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> 721250 T2589 oascc.SolrZkClient.makePath makePath: /collections/collection2/leader_elect/shard2/election
   [junit4]   2> 721260 T2589 oascc.SolrZkClient.makePath makePath: /collections/collection2/leaders/shard2
   [junit4]   2> 721278 T2623 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 721279 T2623 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 721279 T2623 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 721281 T2624 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 721281 T2623 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 721288 T2624 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"active",
   [junit4]   2> 	  "node_name":"127.0.0.1",
   [junit4]   2> 	  "core":"core3",
   [junit4]   2> 	  "core_node_name":"node3",
   [junit4]   2> 	  "collection":"collection2",
   [junit4]   2> 	  "numShards":"3",
   [junit4]   2> 	  "base_url":"http://127.0.0.1/solr/"}
   [junit4]   2> 721288 T2624 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
   [junit4]   2> 721289 T2624 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
   [junit4]   2> 721291 T2623 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 721394 T2627 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> 721394 T2621 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> 721782 T2589 oascc.SolrZkClient.makePath makePath: /collections/collection2/leader_elect/shard1/election
   [junit4]   2> 721794 T2589 oascc.SolrZkClient.makePath makePath: /collections/collection2/leaders/shard1
   [junit4]   2> 721803 T2623 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 721803 T2623 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 721804 T2623 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 721810 T2624 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 721817 T2623 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 721920 T2627 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> 721920 T2621 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> 721956 T2627 oascc.ZkStateReader$3.process Updating live nodes... (0)
   [junit4]   2> 721960 T2589 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:41659 41659
   [junit4]   2> 727060 T2589 oas.SolrTestCaseJ4.tearDown ###Ending testBadQueueItem
   [junit4]   1> client port:0.0.0.0/0.0.0.0:0
   [junit4]   2> 727068 T2589 oas.SolrTestCaseJ4.setUp ###Starting testShardAssignment
   [junit4]   2> 727068 T2589 oasc.ZkTestServer.run STARTING ZK TEST SERVER
   [junit4]   2> 727079 T2628 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
   [junit4]   2> 727179 T2589 oasc.ZkTestServer.run start zk server on port:49826
   [junit4]   2> 727190 T2589 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 727203 T2634 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@3dcc54 name:ZooKeeperConnection Watcher:127.0.0.1:49826 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 727204 T2589 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 727240 T2589 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 727241 T2636 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@b8955 name:ZooKeeperConnection Watcher:127.0.0.1:49826 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 727242 T2589 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 727242 T2589 oascc.SolrZkClient.makePath makePath: /solr
   [junit4]   2> 727244 T2589 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 727245 T2638 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@753b5c name:ZooKeeperConnection Watcher:127.0.0.1:49826/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 727245 T2589 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 727246 T2589 oascc.SolrZkClient.makePath makePath: /live_nodes
   [junit4]   2> 727247 T2589 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 727248 T2640 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1c43006 name:ZooKeeperConnection Watcher:127.0.0.1:49826/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 727248 T2589 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 727251 T2589 oascc.SolrZkClient.makePath makePath: /overseer_elect
   [junit4]   2> 727254 T2589 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
   [junit4]   2> 727258 T2589 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:49826_solr
   [junit4]   2> 727258 T2589 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
   [junit4]   2> 727260 T2589 oasc.Overseer.start Overseer (id=91369732027908099-127.0.0.1:49826_solr-n_0000000000) starting
   [junit4]   2> 727261 T2589 oascc.SolrZkClient.makePath makePath: /overseer/queue
   [junit4]   2> 727263 T2589 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
   [junit4]   2> 727266 T2589 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
   [junit4]   2> 727268 T2642 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
   [junit4]   2> 727268 T2589 oascc.SolrZkClient.makePath makePath: /clusterstate.json
   [junit4]   2> 727269 T2642 oasc.OverseerCollectionProcessor.prioritizeOverseerNodes prioritizing overseer nodes
   [junit4]   2> 727269 T2641 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
   [junit4]   2> 727271 T2589 oascc.SolrZkClient.makePath makePath: /aliases.json
   [junit4]   2> 727272 T2589 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 727274 T2589 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 727274 T2644 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@19e138c name:ZooKeeperConnection Watcher:127.0.0.1:49826/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 727275 T2589 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 727276 T2589 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 727277 T2589 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1
   [junit4]   2> 727279 T2638 oascc.ZkStateReader$3.process Updating live nodes... (1)
   [junit4]   2> 727279 T2644 oascc.ZkStateReader$3.process Updating live nodes... (1)
   [junit4]   2> 727280 T2640 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 727281 T2641 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 727281 T2641 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"active",
   [junit4]   2> 	  "node_name":"127.0.0.1",
   [junit4]   2> 	  "core":"core1",
   [junit4]   2> 	  "core_node_name":"node1",
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "numShards":"3",
   [junit4]   2> 	  "base_url":"http://127.0.0.1/solr/"}
   [junit4]   2> 727282 T2641 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1, shard2, shard3]
   [junit4]   2> 727282 T2641 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard3
   [junit4]   2> 727283 T2640 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 727284 T2638 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> 727284 T2644 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> 727780 T2589 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard3/election
   [junit4]   2> 727787 T2589 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard3
   [junit4]   2> 727793 T2640 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 727794 T2641 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 727795 T2640 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 727797 T2641 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"active",
   [junit4]   2> 	  "node_name":"127.0.0.1",
   [junit4]   2> 	  "core":"core2",
   [junit4]   2> 	  "core_node_name":"node2",
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "numShards":"3",
   [junit4]   2> 	  "base_url":"http://127.0.0.1/solr/"}
   [junit4]   2> 727797 T2641 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
   [junit4]   2> 727798 T2641 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard2
   [junit4]   2> 727800 T2640 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 727902 T2638 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> 727903 T2644 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> 728295 T2589 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard2/election
   [junit4]   2> 728300 T2589 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard2
   [junit4]   2> 728304 T2640 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 728304 T2640 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 728304 T2640 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 728305 T2640 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 728305 T2641 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 728308 T2641 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"active",
   [junit4]   2> 	  "node_name":"127.0.0.1",
   [junit4]   2> 	  "core":"core3",
   [junit4]   2> 	  "core_node_name":"node3",
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "numShards":"3",
   [junit4]   2> 	  "base_url":"http://127.0.0.1/solr/"}
   [junit4]   2> 728308 T2641 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
   [junit4]   2> 728308 T2641 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
   [junit4]   2> 728310 T2640 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 728413 T2638 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> 728413 T2644 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> 728805 T2589 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
   [junit4]   2> 728817 T2589 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 728822 T2640 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 728823 T2640 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 728823 T2640 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 728826 T2641 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 728828 T2640 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 728829 T2641 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"active",
   [junit4]   2> 	  "node_name":"127.0.0.1",
   [junit4]   2> 	  "core":"core4",
   [junit4]   2> 	  "core_node_name":"node4",
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "numShards":"3",
   [junit4]   2> 	  "base_url":"http://127.0.0.1/solr/"}
   [junit4]   2> 728830 T2641 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
   [junit4]   2> 728830 T2641 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard3
   [junit4]   2> 728832 T2640 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 729080 T2644 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> 729080 T2638 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> 729325 T2589 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard3/election
   [junit4]   2> 729333 T2640 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 729333 T2640 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 729333 T2640 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 729334 T2641 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 729335 T2641 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"active",
   [junit4]   2> 	  "node_name":"127.0.0.1",
   [junit4]   2> 	  "core":"core5",
   [junit4]   2> 	  "core_node_name":"node5",
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "numShards":"3",
   [junit4]   2> 	  "base_url":"http://127.0.0.1/solr/"}
   [junit4]   2> 729335 T2641 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
   [junit4]   2> 729336 T2641 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard2
   [junit4]   2> 729338 T2640 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 729439 T2638 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> 729440 T2644 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> 729833 T2589 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard2/election
   [junit4]   2> 729912 T2640 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 729912 T2640 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 729913 T2640 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 729914 T2641 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 729914 T2641 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"active",
   [junit4]   2> 	  "node_name":"127.0.0.1",
   [junit4]   2> 	  "core":"core6",
   [junit4]   2> 	  "core_node_name":"node6",
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "numShards":"3",
   [junit4]   2> 	  "base_url":"http://127.0.0.1/solr/"}
   [junit4]   2> 729915 T2641 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
   [junit4]   2> 729915 T2641 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
   [junit4]   2> 729934 T2640 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 730037 T2644 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> 730037 T2638 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> 730412 T2589 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
   [junit4]   2> 730420 T2644 oascc.ZkStateReader$3.process Updating live nodes... (0)
   [junit4]   2> 730422 T2589 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:49826 49826
   [junit4]   2> 730465 T2589 oas.SolrTestCaseJ4.tearDown ###Ending testShardAssignment
   [junit4]   1> client port:0.0.0.0/0.0.0.0:0
   [junit4]   2> 730469 T2589 oas.SolrTestCaseJ4.setUp ###Starting testPlaceholders
   [junit4]   2> 730469 T2589 oasc.ZkTestServer.run STARTING ZK TEST SERVER
   [junit4]   2> 730470 T2645 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
   [junit4]   2> 730570 T2589 oasc.ZkTestServer.run start zk server on port:60161
   [junit4]   2> 730571 T2589 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 730573 T2651 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@455abb name:ZooKeeperConnection Watcher:127.0.0.1:60161/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 730573 T2589 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 730574 T2589 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 730574 T2653 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@5aa23 name:ZooKeeperConnection Watcher:127.0.0.1:60161 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 730575 T2589 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 730594 T2589 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 730595 T2655 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@102ac06 name:ZooKeeperConnection Watcher:127.0.0.1:60161 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 730596 T2589 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 730596 T2589 oascc.SolrZkClient.makePath makePath: /solr
   [junit4]   2> 730598 T2589 oascc.SolrZkClient.makePath makePath: /live_nodes
   [junit4]   2> 730602 T2589 oascc.SolrZkClient.makePath makePath: /clusterstate.json
   [junit4]   2> 730606 T2589 oascc.SolrZkClient.makePath makePath: /aliases.json
   [junit4]   2> 730608 T2589 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 730613 T2589 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 730615 T2657 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@12aafb0 name:ZooKeeperConnection Watcher:127.0.0.1:60161/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 730615 T2589 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 730617 T2589 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 730621 T2589 oascc.SolrZkClient.makePath makePath: /live_nodes/node1
   [junit4]   2> 730625 T2651 oascc.ZkStateReader$3.process Updating live nodes... (1)
   [junit4]   2> 730625 T2657 oascc.ZkStateReader$3.process Updating live nodes... (1)
   [junit4]   2> 730626 T2589 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 730627 T2659 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@11ab9bf name:ZooKeeperConnection Watcher:127.0.0.1:60161/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 730628 T2589 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 730629 T2589 oascc.SolrZkClient.makePath makePath: /overseer_elect
   [junit4]   2> 730632 T2589 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
   [junit4]   2> 730635 T2589 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:60161_solr
   [junit4]   2> 730635 T2589 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
   [junit4]   2> 730637 T2589 oasc.Overseer.start Overseer (id=91369732249288708-127.0.0.1:60161_solr-n_0000000000) starting
   [junit4]   2> 730638 T2589 oascc.SolrZkClient.makePath makePath: /overseer/queue
   [junit4]   2> 730640 T2589 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
   [junit4]   2> 730643 T2589 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
   [junit4]   2> 730645 T2661 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
   [junit4]   2> 730645 T2660 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
   [junit4]   2> 730646 T2661 oasc.OverseerCollectionProcessor.prioritizeOverseerNodes prioritizing overseer nodes
   [junit4]   2> 730647 T2659 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 730648 T2660 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 730648 T2660 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> 730649 T2660 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1, shard2, shard3, shard4, shard5, shard6, shard7, shard8, shard9, shard10, shard11, shard12]
   [junit4]   2> 730649 T2660 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard6
   [junit4]   2> 730652 T2659 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 730653 T2657 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> 730653 T2651 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> 731147 T2589 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard6/election
   [junit4]   2> 731158 T2589 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard6
   [junit4]   2> 731165 T2659 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 731166 T2589 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 731168 T2660 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 731171 T2651 oascc.ZkStateReader$3.process Updating live nodes... (0)
   [junit4]   2> 731171 T2657 oascc.ZkStateReader$3.process Updating live nodes... (0)
   [junit4]   2> 731173 T2589 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:60161 60161
   [junit4]   2> 731257 T2589 oas.SolrTestCaseJ4.tearDown ###Ending testPlaceholders
   [junit4]   1> client port:0.0.0.0/0.0.0.0:0
   [junit4]   2> 731264 T2589 oas.SolrTestCaseJ4.setUp ###Starting testShardAssignmentBigger
   [junit4]   2> 731265 T2589 oasc.ZkTestServer.run STARTING ZK TEST SERVER
   [junit4]   2> 731265 T2662 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
   [junit4]   2> 731365 T2589 oasc.ZkTestServer.run start zk server on port:55955
   [junit4]   2> 731366 T2589 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 731502 T2668 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@437a5 name:ZooKeeperConnection Watcher:127.0.0.1:55955 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 731502 T2589 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 731525 T2589 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 731526 T2670 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1fe9d61 name:ZooKeeperConnection Watcher:127.0.0.1:55955 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 731527 T2589 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 731527 T2589 oascc.SolrZkClient.makePath makePath: /solr
   [junit4]   2> 731529 T2589 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 731530 T2672 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@12b71ce name:ZooKeeperConnection Watcher:127.0.0.1:55955/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 731530 T2589 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 731531 T2589 oascc.SolrZkClient.makePath makePath: /live_nodes
   [junit4]   2> 731532 T2589 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 731533 T2674 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1de5ff4 name:ZooKeeperConnection Watcher:127.0.0.1:55955/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 731534 T2589 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 731534 T2589 oascc.SolrZkClient.makePath makePath: /overseer_elect
   [junit4]   2> 731536 T2589 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
   [junit4]   2> 731539 T2589 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:55955_solr
   [junit4]   2> 731539 T2589 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
   [junit4]   2> 731541 T2589 oasc.Overseer.start Overseer (id=91369732301324291-127.0.0.1:55955_solr-n_0000000000) starting
   [junit4]   2> 731542 T2589 oascc.SolrZkClient.makePath makePath: /overseer/queue
   [junit4]   2> 731544 T2589 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
   [junit4]   2> 731547 T2589 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
   [junit4]   2> 731549 T2676 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
   [junit4]   2> 731550 T2589 oascc.SolrZkClient.makePath makePath: /clusterstate.json
   [junit4]   2> 731550 T2676 oasc.OverseerCollectionProcessor.prioritizeOverseerNodes prioritizing overseer nodes
   [junit4]   2> 731550 T2675 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
   [junit4]   2> 731553 T2589 oascc.SolrZkClient.makePath makePath: /aliases.json
   [junit4]   2> 731554 T2589 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 731556 T2589 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 731557 T2678 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@553609 name:ZooKeeperConnection Watcher:127.0.0.1:55955/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 731557 T2589 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 731558 T2589 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 731559 T2589 oascc.SolrZkClient.makePath makePath: /live_nodes/node0
   [junit4]   2> 731561 T2672 oascc.ZkStateReader$3.process Updating live nodes... (1)
   [junit4]   2> 731561 T2678 oascc.ZkStateReader$3.process Updating live nodes... (1)
   [junit4]   2> 731561 T2589 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 731562 T2680 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@180f6f1 name:ZooKeeperConnection Watcher:127.0.0.1:55955/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 731563 T2589 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 731564 T2589 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 731565 T2589 oascc.SolrZkClient.makePath makePath: /live_nodes/node1
   [junit4]   2> 731568 T2672 oascc.ZkStateReader$3.process Updating live nodes... (2)
   [junit4]   2> 731568 T2678 oascc.ZkStateReader$3.process Updating live nodes... (2)
   [junit4]   2> 731568 T2680 oascc.ZkStateReader$3.process Updating live nodes... (2)
   [junit4]   2> 731568 T2589 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 731569 T2682 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@6bed86 name:ZooKeeperConnection Watcher:127.0.0.1:55955/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 731570 T2589 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 731571 T2589 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 731573 T2589 oascc.SolrZkClient.makePath makePath: /live_nodes/node2
   [junit4]   2> 731575 T2672 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 731575 T2678 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 731575 T2682 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 731575 T2680 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 731575 T2589 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 731577 T2684 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1c0e708 name:ZooKeeperConnection Watcher:127.0.0.1:55955/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 731577 T2589 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 731578 T2589 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 731579 T2589 oascc.SolrZkClient.makePath makePath: /live_nodes/node3
   [junit4]   2> 731582 T2678 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 731582 T2680 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 731582 T2672 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 731582 T2682 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 731582 T2684 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 731582 T2589 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 731583 T2686 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@7bdca9 name:ZooKeeperConnection Watcher:127.0.0.1:55955/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 731584 T2589 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 731584 T2589 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 731586 T2589 oascc.SolrZkClient.makePath makePath: /live_nodes/node4
   [junit4]   2> 731588 T2680 oascc.ZkStateReader$3.process Updating live nodes... (5)
   [junit4]   2> 731589 T2686 oascc.ZkStateReader$3.process Updating live nodes... (5)
   [junit4]   2> 731589 T2672 oascc.ZkStateReader$3.process Updating live nodes... (5)
   [junit4]   2> 731589 T2682 oascc.ZkStateReader$3.process Updating live nodes... (5)
   [junit4]   2> 731589 T2684 oascc.ZkStateReader$3.process Updating live nodes... (5)
   [junit4]   2> 731589 T2678 oascc.ZkStateReader$3.process Updating live nodes... (5)
   [junit4]   2> 731589 T2589 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 731590 T2688 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@e3a27e name:ZooKeeperConnection Watcher:127.0.0.1:55955/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 731591 T2589 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 731592 T2589 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 731593 T2589 oascc.SolrZkClient.makePath makePath: /live_nodes/node5
   [junit4]   2> 731596 T2686 oascc.ZkStateReader$3.process Updating live nodes... (6)
   [junit4]   2> 731596 T2682 oascc.ZkStateReader$3.process Updating live nodes... (6)
   [junit4]   2> 731596 T2684 oascc.ZkStateReader$3.process Updating live nodes... (6)
   [junit4]   2> 731596 T2672 oascc.ZkStateReader$3.process Updating live nodes... (6)
   [junit4]   2> 731597 T2589 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 731599 T2690 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1f401ce name:ZooKeeperConnection Watcher:127.0.0.1:55955/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 731599 T2678 oascc.ZkStateReader$3.process Updating live nodes... (6)
   [junit4]   2> 731599 T2680 oascc.ZkStateReader$3.process Updating live nodes... (6)
   [junit4]   2> 731599 T2688 oascc.ZkStateReader$3.process Updating live nodes... (6)
   [junit4]   2> 731599 T2589 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 731600 T2589 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 731602 T2589 oascc.SolrZkClient.makePath makePath: /live_nodes/node6
   [junit4]   2> 731605 T2682 oascc.ZkStateReader$3.process Updating live nodes... (7)
   [junit4]   2> 731605 T2686 oascc.ZkStateReader$3.process Updating live nodes... (7)
   [junit4]   2> 731605 T2672 oascc.ZkStateReader$3.process Updating live nodes... (7)
   [junit4]   2> 731605 T2688 oascc.ZkStateReader$3.process Updating live nodes... (7)
   [junit4]   2> 731605 T2678 oascc.ZkStateReader$3.process Updating live nodes... (7)
   [junit4]   2> 731605 T2680 oascc.ZkStateReader$3.process Updating live nodes... (7)
   [junit4]   2> 731605 T2684 oascc.ZkStateReader$3.process Updating live nodes... (7)
   [junit4]   2> 731606 T2589 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 731606 T2690 oascc.ZkStateReader$3.process Updating live nodes... (7)
   [junit4]   2> 731607 T2692 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.Connecti

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

entCnxn.java:519)
   [junit4]   2> 	at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:495)
   [junit4]   2> 
   [junit4]   2> 752342 T3114 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:259)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:256)
   [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:256)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:92)
   [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:137)
   [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> 747984 T3106 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
   [junit4]   2> 752341 T2589 oas.SolrTestCaseJ4.tearDown ###Ending testShardLeaderChange
   [junit4]   2> 752341 T3098 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:259)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:256)
   [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:256)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:92)
   [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:137)
   [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> 752343 T3106 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:259)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:256)
   [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:256)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:92)
   [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:137)
   [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> 752344 T3106 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:259)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:256)
   [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:256)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:92)
   [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:137)
   [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]   1> client port:0.0.0.0/0.0.0.0:0
   [junit4]   2> 752345 T2589 oas.SolrTestCaseJ4.initCore ####initCore
   [junit4]   2> 752345 T2589 oas.SolrTestCaseJ4.initCore ####initCore end
   [junit4]   2> 755345 T2589 oas.SolrTestCaseJ4.deleteCore ###deleteCore
   [junit4]   2> NOTE: test params are: codec=Lucene46: {}, docValues:{}, sim=RandomSimilarityProvider(queryNorm=true,coord=crazy): {}, locale=ko_KR, timezone=Mideast/Riyadh89
   [junit4]   2> NOTE: Linux 3.8.0-36-generic i386/Oracle Corporation 1.7.0_51 (32-bit)/cpus=8,threads=1,free=199507816,total=295960576
   [junit4]   2> NOTE: All tests run in this JVM: [TestJmxIntegration, BasicDistributedZk2Test, SolrCmdDistributorTest, HdfsDirectoryTest, FileUtilsTest, SolrTestCaseJ4Test, NotRequiredUniqueKeyTest, TestCollapseQParserPlugin, TestSweetSpotSimilarityFactory, ChaosMonkeyNothingIsSafeTest, TestXIncludeConfig, AddBlockUpdateTest, TestDefaultSimilarityFactory, DirectSolrSpellCheckerTest, BadCopyFieldTest, SuggesterWFSTTest, AliasIntegrationTest, PrimUtilsTest, TestDistributedSearch, AlternateDirectoryTest, TestWordDelimiterFilterFactory, TestStandardQParsers, NumericFieldsTest, TestRangeQuery, SolrXmlInZkTest, SpellCheckCollatorTest, SortByFunctionTest, HdfsCollectionsAPIDistributedZkTest, DisMaxRequestHandlerTest, TestDFRSimilarityFactory, TestIBSimilarityFactory, OpenCloseCoreStressTest, TestSchemaResource, TestNumberUtils, DirectSolrConnectionTest, TestSolrXml, RequestHandlersTest, TestIndexSearcher, TestCopyFieldCollectionResource, TestSchemaNameResource, TestClassNameShortening, IndexSchemaRuntimeFieldTest, ZkNodePropsTest, OutputWriterTest, TestBinaryResponseWriter, SuggesterTSTTest, JSONWriterTest, TestCollationField, ChaosMonkeySafeLeaderTest, ZkSolrClientTest, CursorMarkTest, TestDistribDocBasedVersion, TestFuzzyAnalyzedSuggestions, TestReload, TestAnalyzedSuggestions, TestCloudManagedSchema, TestIndexingPerformance, UniqFieldsUpdateProcessorFactoryTest, TestFieldTypeResource, BlockDirectoryTest, CurrencyFieldOpenExchangeTest, SolrIndexConfigTest, TestSchemaVersionResource, LeaderElectionIntegrationTest, DistributedQueryComponentCustomSortTest, HighlighterConfigTest, SolrRequestParserTest, TestInitQParser, DistanceFunctionTest, PluginInfoTest, SimplePostToolTest, IndexBasedSpellCheckerTest, FieldAnalysisRequestHandlerTest, TestLazyCores, AnalysisErrorHandlingTest, BadIndexSchemaTest, TestStressLucene, MultiTermTest, SpellingQueryConverterTest, TestRTGBase, TestFileDictionaryLookup, TestCSVLoader, TestOverriddenPrefixQueryForCustomFieldType, SolrCoreCheckLockOnStartupTest, TestHighlightDedupGrouping, BlockCacheTest, TestPartialUpdateDeduplication, HighlighterTest, TestCSVResponseWriter, TestCodecSupport, TestUtils, XmlUpdateRequestHandlerTest, OverseerTest]
   [junit4] Completed on J1 in 55.29s, 9 tests, 1 error <<< FAILURES!

[...truncated 598 lines...]
BUILD FAILED
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/build.xml:465: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/build.xml:445: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/build.xml:39: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/extra-targets.xml:37: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build.xml:189: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/common-build.xml:490: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/lucene/common-build.xml:1274: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/lucene/common-build.xml:907: There were test failures: 378 suites, 1618 tests, 1 error, 49 ignored (20 assumptions)

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



Mime
View raw message