lucene-dev mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From Policeman Jenkins Server <jenk...@thetaphi.de>
Subject [JENKINS] Lucene-Solr-4.x-Linux (32bit/jrockit-jdk1.6.0_45-R28.2.7-4.1.0) - Build # 9593 - Failure!
Date Fri, 07 Mar 2014 02:58:42 GMT
Build: http://jenkins.thetaphi.de/job/Lucene-Solr-4.x-Linux/9593/
Java: 32bit/jrockit-jdk1.6.0_45-R28.2.7-4.1.0 -XnoOpt

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([599938A11E6E263A:5D91B7520CCBC91B]: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:39)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
	at java.lang.reflect.Method.invoke(Method.java:597)
	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:738)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:774)
	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:683)
	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:40)
	at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:44)
	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:56)
	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:662)
Caused by: org.apache.solr.common.SolrException: org.apache.zookeeper.KeeperException$NodeExistsException: KeeperErrorCode = NodeExists for /collections/collection1/leaders/shard1
	at org.apache.solr.common.util.RetryUtil.retryOnThrowable(RetryUtil.java:40)
	at org.apache.solr.cloud.ShardLeaderElectionContextBase.runLeaderProcess(ElectionContext.java:122)
	at org.apache.solr.cloud.LeaderElector.runIamLeaderProcess(LeaderElector.java:165)
	... 45 more
Caused by: org.apache.zookeeper.KeeperException$NodeExistsException: KeeperErrorCode = NodeExists for /collections/collection1/leaders/shard1
	at org.apache.zookeeper.KeeperException.create(KeeperException.java:119)
	at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
	at org.apache.zookeeper.ZooKeeper.create(ZooKeeper.java:783)
	at org.apache.solr.common.cloud.SolrZkClient$10.execute(SolrZkClient.java: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:34)
	at org.apache.solr.cloud.ShardLeaderElectionContextBase.runLeaderProcess(ElectionContext.java:122)
	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:39)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
	at java.lang.reflect.Method.invoke(Method.java:597)
	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)
	... 3 more




Build Log:
[...truncated 10006 lines...]
   [junit4] Suite: org.apache.solr.cloud.OverseerTest
   [junit4]   2> 1016853 T3660 oas.SolrTestCaseJ4.buildSSLConfig Randomized ssl (false) and clientAuth (false)
   [junit4]   2> 1016854 T3660 oas.SolrTestCaseJ4.initCore ####initCore
   [junit4]   2> Creating dataDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./solrtest-OverseerTest-1394160349654
   [junit4]   2> 1016854 T3660 oas.SolrTestCaseJ4.initCore ####initCore end
   [junit4]   2> 1016875 T3660 oas.SolrTestCaseJ4.setUp ###Starting testDoubleAssignment
   [junit4]   2> 1016877 T3660 oasc.ZkTestServer.run STARTING ZK TEST SERVER
   [junit4]   2> 1016877 T3661 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
   [junit4]   2> 1016977 T3660 oasc.ZkTestServer.run start zk server on port:50595
   [junit4]   2> 1016979 T3660 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1017058 T3667 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1b9eb77d name:ZooKeeperConnection Watcher:127.0.0.1:50595/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1017059 T3660 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1017060 T3660 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1017062 T3669 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1b8820e5 name:ZooKeeperConnection Watcher:127.0.0.1:50595 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1017063 T3660 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1017067 T3660 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1017070 T3671 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1b88aa4d name:ZooKeeperConnection Watcher:127.0.0.1:50595 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1017070 T3660 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1017071 T3660 oascc.SolrZkClient.makePath makePath: /solr
   [junit4]   2> 1017077 T3660 oascc.SolrZkClient.makePath makePath: /live_nodes
   [junit4]   2> 1017085 T3660 oascc.SolrZkClient.makePath makePath: /clusterstate.json
   [junit4]   2> 1017094 T3660 oascc.SolrZkClient.makePath makePath: /aliases.json
   [junit4]   2> 1017099 T3660 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 1017108 T3660 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1017130 T3673 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1b8a8ca1 name:ZooKeeperConnection Watcher:127.0.0.1:50595/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1017130 T3660 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1017134 T3660 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 1017141 T3660 oascc.SolrZkClient.makePath makePath: /live_nodes/node1
   [junit4]   2> 1017148 T3667 oascc.ZkStateReader$3.process Updating live nodes... (1)
   [junit4]   2> 1017148 T3673 oascc.ZkStateReader$3.process Updating live nodes... (1)
   [junit4]   2> 1017152 T3660 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1017154 T3675 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1afc3258 name:ZooKeeperConnection Watcher:127.0.0.1:50595/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1017154 T3660 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1017156 T3660 oascc.SolrZkClient.makePath makePath: /overseer_elect
   [junit4]   2> 1017162 T3660 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
   [junit4]   2> 1017167 T3660 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:50595_solr
   [junit4]   2> 1017168 T3660 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
   [junit4]   2> 1017170 T3660 oasc.Overseer.start Overseer (id=91367692676562948-127.0.0.1:50595_solr-n_0000000000) starting
   [junit4]   2> 1017173 T3660 oascc.SolrZkClient.makePath makePath: /overseer/queue
   [junit4]   2> 1017177 T3660 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
   [junit4]   2> 1017182 T3660 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
   [junit4]   2> 1017184 T3677 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
   [junit4]   2> 1017185 T3677 oasc.OverseerCollectionProcessor.prioritizeOverseerNodes prioritizing overseer nodes
   [junit4]   2> 1017186 T3676 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
   [junit4]   2> 1017190 T3675 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1017192 T3676 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1017193 T3676 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> 1017193 T3676 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1]
   [junit4]   2> 1017193 T3676 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
   [junit4]   2> 1017196 T3675 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1017197 T3673 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> 1017197 T3667 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> 1017691 T3660 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
   [junit4]   2> 1017703 T3660 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 1017709 T3675 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1017711 T3660 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1017712 T3676 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1017715 T3667 oascc.ZkStateReader$3.process Updating live nodes... (0)
   [junit4]   2> 1017715 T3673 oascc.ZkStateReader$3.process Updating live nodes... (0)
   [junit4]   2> 1017720 T3660 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1017721 T3675 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1017721 T3679 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1afd4ade name:ZooKeeperConnection Watcher:127.0.0.1:50595/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1017721 T3660 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1017723 T3660 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 1017726 T3660 oascc.SolrZkClient.makePath makePath: /live_nodes/node1
   [junit4]   2> 1017728 T3667 oascc.ZkStateReader$3.process Updating live nodes... (1)
   [junit4]   2> 1017732 T3679 oascc.ZkStateReader$3.process Updating live nodes... (1)
   [junit4]   2> 1017734 T3675 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1017734 T3660 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
   [junit4]   2> 1017736 T3676 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> 1017736 T3676 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
   [junit4]   2> 1017740 T3675 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1017743 T3660 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 1017749 T3675 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1017755 T3675 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1017858 T3679 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> 1017858 T3667 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> 1017860 T3660 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1017864 T3667 oascc.ZkStateReader$3.process Updating live nodes... (0)
   [junit4]   2> 1017864 T3679 oascc.ZkStateReader$3.process Updating live nodes... (0)
   [junit4]   2> 1017866 T3660 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:50595 50595
   [junit4]   2> 1018265 T3660 oas.SolrTestCaseJ4.tearDown ###Ending testDoubleAssignment
   [junit4]   1> client port:0.0.0.0/0.0.0.0:0
   [junit4]   2> 1018288 T3660 oas.SolrTestCaseJ4.setUp ###Starting testBadQueueItem
   [junit4]   2> 1018290 T3660 oasc.ZkTestServer.run STARTING ZK TEST SERVER
   [junit4]   2> 1018290 T3680 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
   [junit4]   2> 1018390 T3660 oasc.ZkTestServer.run start zk server on port:44985
   [junit4]   2> 1018391 T3660 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1018393 T3686 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1b1fa1d5 name:ZooKeeperConnection Watcher:127.0.0.1:44985 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1018393 T3660 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1018422 T3660 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1018422 T3688 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1b356b16 name:ZooKeeperConnection Watcher:127.0.0.1:44985 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1018423 T3660 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1018423 T3660 oascc.SolrZkClient.makePath makePath: /solr
   [junit4]   2> 1018426 T3660 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1018427 T3690 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1b33e47d name:ZooKeeperConnection Watcher:127.0.0.1:44985/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1018427 T3660 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1018428 T3660 oascc.SolrZkClient.makePath makePath: /live_nodes
   [junit4]   2> 1018430 T3660 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1018431 T3692 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1b343dc8 name:ZooKeeperConnection Watcher:127.0.0.1:44985/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1018431 T3660 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1018432 T3660 oascc.SolrZkClient.makePath makePath: /overseer_elect
   [junit4]   2> 1018435 T3660 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
   [junit4]   2> 1018439 T3660 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:44985_solr
   [junit4]   2> 1018440 T3660 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
   [junit4]   2> 1018443 T3660 oasc.Overseer.start Overseer (id=91367692769230851-127.0.0.1:44985_solr-n_0000000000) starting
   [junit4]   2> 1018445 T3660 oascc.SolrZkClient.makePath makePath: /overseer/queue
   [junit4]   2> 1018451 T3660 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
   [junit4]   2> 1018456 T3660 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
   [junit4]   2> 1018461 T3694 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
   [junit4]   2> 1018464 T3660 oascc.SolrZkClient.makePath makePath: /clusterstate.json
   [junit4]   2> 1018464 T3694 oasc.OverseerCollectionProcessor.prioritizeOverseerNodes prioritizing overseer nodes
   [junit4]   2> 1018465 T3693 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
   [junit4]   2> 1018470 T3660 oascc.SolrZkClient.makePath makePath: /aliases.json
   [junit4]   2> 1018472 T3660 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 1018476 T3660 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1018477 T3696 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1b35be29 name:ZooKeeperConnection Watcher:127.0.0.1:44985/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1018478 T3660 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1018479 T3660 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 1018482 T3660 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1
   [junit4]   2> 1018486 T3690 oascc.ZkStateReader$3.process Updating live nodes... (1)
   [junit4]   2> 1018486 T3696 oascc.ZkStateReader$3.process Updating live nodes... (1)
   [junit4]   2> 1018488 T3692 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1018490 T3693 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1018491 T3693 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> 1018491 T3693 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1, shard2, shard3]
   [junit4]   2> 1018492 T3693 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
   [junit4]   2> 1018495 T3692 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1018496 T3696 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> 1018496 T3690 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> 1018988 T3660 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
   [junit4]   2> 1019000 T3660 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 1019007 T3692 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1019010 T3692 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1019011 T3693 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1019015 T3693 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> 1019016 T3693 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
   [junit4]   2> 1019016 T3693 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard2
   [junit4]   2> 1019019 T3692 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1019122 T3690 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> 1019123 T3696 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> 1019510 T3660 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard2/election
   [junit4]   2> 1019523 T3660 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard2
   [junit4]   2> 1019530 T3692 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1019530 T3692 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1019531 T3692 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1019535 T3692 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1019536 T3693 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1019540 T3693 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> 1019540 T3693 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
   [junit4]   2> 1019540 T3693 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard3
   [junit4]   2> 1019543 T3692 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1019646 T3696 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> 1019646 T3690 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> 1020035 T3660 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard3/election
   [junit4]   2> 1020045 T3660 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard3
   [junit4]   2> 1020051 T3692 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1020051 T3692 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1020052 T3692 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1020053 T3693 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1020057 T3692 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1020159 T3690 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> 1020159 T3696 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> 1020205 T3692 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1020205 T3692 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1020205 T3692 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1020207 T3693 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1020208 T3693 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> 1020208 T3692 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1020213 T3693 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> 1020216 T3692 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1020218 T3693 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> 1020218 T3693 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection2 with shards [shard1, shard2, shard3]
   [junit4]   2> 1020218 T3693 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
   [junit4]   2> 1020222 T3692 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1020325 T3696 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> 1020325 T3690 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> 1020712 T3660 oascc.SolrZkClient.makePath makePath: /collections/collection2/leader_elect/shard1/election
   [junit4]   2> 1020725 T3660 oascc.SolrZkClient.makePath makePath: /collections/collection2/leaders/shard1
   [junit4]   2> 1020737 T3692 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1020737 T3692 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1020738 T3692 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1020740 T3692 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1020741 T3693 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1020746 T3693 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> 1020746 T3693 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
   [junit4]   2> 1020746 T3693 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard2
   [junit4]   2> 1020750 T3692 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1020854 T3690 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> 1020854 T3696 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> 1021241 T3660 oascc.SolrZkClient.makePath makePath: /collections/collection2/leader_elect/shard2/election
   [junit4]   2> 1021250 T3660 oascc.SolrZkClient.makePath makePath: /collections/collection2/leaders/shard2
   [junit4]   2> 1021256 T3692 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1021257 T3692 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1021257 T3692 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1021259 T3692 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1021260 T3693 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1021266 T3693 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> 1021266 T3693 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
   [junit4]   2> 1021266 T3693 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard3
   [junit4]   2> 1021269 T3692 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1021373 T3696 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> 1021373 T3690 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> 1021759 T3660 oascc.SolrZkClient.makePath makePath: /collections/collection2/leader_elect/shard3/election
   [junit4]   2> 1021770 T3660 oascc.SolrZkClient.makePath makePath: /collections/collection2/leaders/shard3
   [junit4]   2> 1021779 T3692 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1021779 T3692 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1021780 T3692 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1021784 T3693 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1021791 T3692 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1021896 T3696 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> 1021896 T3690 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> 1021935 T3696 oascc.ZkStateReader$3.process Updating live nodes... (0)
   [junit4]   2> 1021939 T3660 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:44985 44985
   [junit4]   2> 1022474 T3660 oas.SolrTestCaseJ4.tearDown ###Ending testBadQueueItem
   [junit4]   1> client port:0.0.0.0/0.0.0.0:0
   [junit4]   2> 1022513 T3660 oas.SolrTestCaseJ4.setUp ###Starting testShardLeaderChange
   [junit4]   2> 1022514 T3660 oasc.ZkTestServer.run STARTING ZK TEST SERVER
   [junit4]   2> 1022515 T3697 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
   [junit4]   2> 1022615 T3660 oasc.ZkTestServer.run start zk server on port:38547
   [junit4]   2> 1022616 T3660 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1022619 T3703 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1b559b2c name:ZooKeeperConnection Watcher:127.0.0.1:38547/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1022620 T3660 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1022622 T3660 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1022623 T3705 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1b55c377 name:ZooKeeperConnection Watcher:127.0.0.1:38547 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1022624 T3660 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1022715 T3660 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1022716 T3707 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1b685d7f name:ZooKeeperConnection Watcher:127.0.0.1:38547 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1022717 T3660 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1022718 T3660 oascc.SolrZkClient.makePath makePath: /solr
   [junit4]   2> 1022724 T3660 oascc.SolrZkClient.makePath makePath: /live_nodes
   [junit4]   2> 1022730 T3660 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1022731 T3708 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1022732 T3710 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1b66e8c9 name:ZooKeeperConnection Watcher:127.0.0.1:38547/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1022732 T3660 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1022734 T3712 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1b7327f1 name:ZooKeeperConnection Watcher:127.0.0.1:38547/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1022734 T3708 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1022734 T3660 oascc.SolrZkClient.makePath makePath: /clusterstate.json
   [junit4]   2> 1022736 T3708 oascc.SolrZkClient.makePath makePath: /overseer_elect
   [junit4]   2> 1022742 T3660 oascc.SolrZkClient.makePath makePath: /aliases.json
   [junit4]   2> 1022743 T3708 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
   [junit4]   2> 1022748 T3660 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 1022756 T3708 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:38547_solr
   [junit4]   2> 1022756 T3660 oascc.SolrZkClient.makePath makePath: /live_nodes/node1
   [junit4]   2> 1022756 T3708 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
   [junit4]   2> 1022765 T3710 oascc.ZkStateReader$3.process Updating live nodes... (1)
   [junit4]   2> 1022765 T3708 oasc.Overseer.start Overseer (id=91367693046513668-127.0.0.1:38547_solr-n_0000000000) starting
   [junit4]   2> 1022769 T3660 oascc.SolrZkClient.makePath makePath: /overseer/queue
   [junit4]   2> 1022773 T3708 oascc.SolrZkClient.makePath makePath: /overseer/queue
   [junit4]   2> 1022781 T3708 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
   [junit4]   2> 1022791 T3708 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
   [junit4]   2> 1022797 T3714 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
   [junit4]   2> 1022797 T3708 oasc.OverseerTest$OverseerRestarter.run Killing overseer.
   [junit4]   2> 1022800 T3714 oasc.OverseerCollectionProcessor.prioritizeOverseerNodes prioritizing overseer nodes
   [junit4]   2> 1022801 T3708 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1022803 T3716 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1b739414 name:ZooKeeperConnection Watcher:127.0.0.1:38547/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1022804 T3708 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1022804 T3714 oasc.OverseerCollectionProcessor.run ERROR Unable to prioritize overseer  java.lang.InterruptedException: sleep interrupted
   [junit4]   2> 	at java.lang.Thread.sleep(Native Method)
   [junit4]   2> 	at org.apache.solr.common.cloud.ZkCmdExecutor.retryDelay(ZkCmdExecutor.java:119)
   [junit4]   2> 	at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:87)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient.exists(SolrZkClient.java:222)
   [junit4]   2> 	at org.apache.solr.cloud.OverseerCollectionProcessor.prioritizeOverseerNodes(OverseerCollectionProcessor.java:234)
   [junit4]   2> 	at org.apache.solr.cloud.OverseerCollectionProcessor.run(OverseerCollectionProcessor.java:185)
   [junit4]   2> 	at java.lang.Thread.run(Thread.java:662)
   [junit4]   2> 
   [junit4]   2> 1022805 T3714 oasc.OverseerCollectionProcessor.amILeader  org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /overseer_elect/leader
   [junit4]   2> 	at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
   [junit4]   2> 	at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
   [junit4]   2> 	at org.apache.zookeeper.ZooKeeper.getData(ZooKeeper.java: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.OverseerCollectionProcessor.amILeader(OverseerCollectionProcessor.java:362)
   [junit4]   2> 	at org.apache.solr.cloud.OverseerCollectionProcessor.run(OverseerCollectionProcessor.java:192)
   [junit4]   2> 	at java.lang.Thread.run(Thread.java:662)
   [junit4]   2> 
   [junit4]   2> 1022806 T3714 oasc.OverseerCollectionProcessor.amILeader According to ZK I (id=91367693046513668-127.0.0.1:38547_solr-n_0000000000) am no longer a leader.
   [junit4]   2> 1022811 T3708 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:38547_solr
   [junit4]   2> 1022811 T3708 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
   [junit4]   2> 1022818 T3708 oasc.Overseer.start Overseer (id=91367693046513669-127.0.0.1:38547_solr-n_0000000001) starting
   [junit4]   2> 1022831 T3718 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
   [junit4]   2> 1022833 T3718 oasc.OverseerCollectionProcessor.prioritizeOverseerNodes prioritizing overseer nodes
   [junit4]   2> 1022834 T3717 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
   [junit4]   2> 1022840 T3717 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1022842 T3717 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"state1",
   [junit4]   2> 	  "node_name":"node1",
   [junit4]   2> 	  "core":"core1",
   [junit4]   2> 	  "core_node_name":"node1",
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "numShards":"1",
   [junit4]   2> 	  "base_url":"http://node1/solr/"}
   [junit4]   2> 1022842 T3717 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1]
   [junit4]   2> 1022842 T3717 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
   [junit4]   2> 1022850 T3716 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1022853 T3710 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> 1023279 T3660 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
   [junit4]   2> 1023291 T3660 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 1023299 T3716 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1023305 T3716 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1023306 T3660 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
   [junit4]   2> 1023306 T3717 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1023313 T3717 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"state2",
   [junit4]   2> 	  "node_name":"node1",
   [junit4]   2> 	  "core":"core1",
   [junit4]   2> 	  "core_node_name":"node1",
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "numShards":"1",
   [junit4]   2> 	  "base_url":"http://node1/solr/"}
   [junit4]   2> 1023313 T3717 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
   [junit4]   2> 1023316 T3660 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1023317 T3716 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1023317 T3720 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1b67c2ae name:ZooKeeperConnection Watcher:127.0.0.1:38547/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1023318 T3660 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1023320 T3660 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 1023324 T3660 oascc.SolrZkClient.makePath makePath: /live_nodes/node2
   [junit4]   2> 1023328 T3710 oascc.ZkStateReader$3.process Updating live nodes... (2)
   [junit4]   2> 1023328 T3720 oascc.ZkStateReader$3.process Updating live nodes... (2)
   [junit4]   2> 1023333 T3716 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1023333 T3660 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
   [junit4]   2> 1023336 T3717 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"state1",
   [junit4]   2> 	  "node_name":"node1",
   [junit4]   2> 	  "core":"core1",
   [junit4]   2> 	  "core_node_name":"node1",
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "numShards":"1",
   [junit4]   2> 	  "base_url":"http://node1/solr/"}
   [junit4]   2> 1023337 T3717 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
   [junit4]   2> 1023341 T3716 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1023346 T3660 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1023446 T3720 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
   [junit4]   2> 1023446 T3710 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
   [junit4]   2> 1023548 T3660 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1023551 T3716 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1023551 T3716 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1023552 T3716 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1023554 T3717 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1023556 T3717 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"state2",
   [junit4]   2> 	  "node_name":"node2",
   [junit4]   2> 	  "core":"core4",
   [junit4]   2> 	  "core_node_name":"node2",
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "numShards":"1",
   [junit4]   2> 	  "base_url":"http://node2/solr/"}
   [junit4]   2> 1023556 T3717 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=1
   [junit4]   2> 1023556 T3717 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
   [junit4]   2> 1023559 T3716 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1023664 T3720 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
   [junit4]   2> 1023664 T3710 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
   [junit4]   2> 1024052 T3660 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
   [junit4]   2> 1024062 T3720 oascc.ZkStateReader$3.process Updating live nodes... (1)
   [junit4]   2> 1024062 T3710 oascc.ZkStateReader$3.process Updating live nodes... (1)
   [junit4]   2> 1024064 T3660 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1024064 T3720 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 1024072 T3716 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1024072 T3716 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1024073 T3716 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1024074 T3717 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1024078 T3716 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1024181 T3720 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> 1024266 T3660 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1024268 T3660 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1024269 T3722 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1b68c6bd name:ZooKeeperConnection Watcher:127.0.0.1:38547/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1024269 T3660 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1024271 T3660 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 1024274 T3660 oascc.SolrZkClient.makePath makePath: /live_nodes/node1
   [junit4]   2> 1024277 T3720 oascc.ZkStateReader$3.process Updating live nodes... (2)
   [junit4]   2> 1024277 T3722 oascc.ZkStateReader$3.process Updating live nodes... (2)
   [junit4]   2> 1024280 T3716 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1024280 T3660 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
   [junit4]   2> 1024280 T3716 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1024281 T3716 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1024283 T3717 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1024284 T3717 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"state1",
   [junit4]   2> 	  "node_name":"node1",
   [junit4]   2> 	  "core":"core1",
   [junit4]   2> 	  "core_node_name":"node1",
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "numShards":"1",
   [junit4]   2> 	  "base_url":"http://node1/solr/"}
   [junit4]   2> 1024284 T3717 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
   [junit4]   2> 1024287 T3716 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1024291 T3722 oascc.ZkStateReader$3.process Updating live nodes... (1)
   [junit4]   2> 1024291 T3720 oascc.ZkStateReader$3.process Updating live nodes... (1)
   [junit4]   2> 1024293 T3722 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 1024294 T3660 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
   [junit4]   2> 1024295 T3716 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1024297 T3717 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"state2",
   [junit4]   2> 	  "node_name":"node1",
   [junit4]   2> 	  "core":"core1",
   [junit4]   2> 	  "core_node_name":"node1",
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "numShards":"1",
   [junit4]   2> 	  "base_url":"http://node1/solr/"}
   [junit4]   2> 1024297 T3717 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
   [junit4]   2> 1024301 T3716 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1024307 T3716 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1024307 T3660 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1024308 T3724 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1b7dc009 name:ZooKeeperConnection Watcher:127.0.0.1:38547/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1024309 T3660 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1024310 T3660 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 1024313 T3660 oascc.SolrZkClient.makePath makePath: /live_nodes/node2
   [junit4]   2> 1024316 T3722 oascc.ZkStateReader$3.process Updating live nodes... (2)
   [junit4]   2> 1024316 T3724 oascc.ZkStateReader$3.process Updating live nodes... (2)
   [junit4]   2> 1024319 T3716 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1024319 T3660 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
   [junit4]   2> 1024321 T3717 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"state1",
   [junit4]   2> 	  "node_name":"node1",
   [junit4]   2> 	  "core":"core1",
   [junit4]   2> 	  "core_node_name":"node1",
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "numShards":"1",
   [junit4]   2> 	  "base_url":"http://node1/solr/"}
   [junit4]   2> 1024321 T3717 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
   [junit4]   2> 1024325 T3716 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1024329 T3660 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1024333 T3708 oasc.OverseerTest$OverseerRestarter.run Killing overseer.
   [junit4]   2> 1024334 T3708 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1024335 T3726 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1b73e5fd name:ZooKeeperConnection Watcher:127.0.0.1:38547/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1024335 T3708 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1024340 T3708 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:38547_solr
   [junit4]   2> 1024340 T3708 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
   [junit4]   2> 1024343 T3708 oasc.Overseer.start Overseer (id=91367693046513673-127.0.0.1:38547_solr-n_0000000002) starting
   [junit4]   2> 1024360 T3728 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
   [junit4]   2> 1024361 T3728 oasc.OverseerCollectionProcessor.prioritizeOverseerNodes prioritizing overseer nodes
   [junit4]   2> 1024363 T3727 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1024364 T3727 oasc.Overseer$ClusterStateUpdater.run Replaying operations from work queue.
   [junit4]   2> 1024365 T3727 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"state1",
   [junit4]   2> 	  "node_name":"node1",
   [junit4]   2> 	  "core":"core1",
   [junit4]   2> 	  "core_node_name":"node1",
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "numShards":"1",
   [junit4]   2> 	  "base_url":"http://node1/solr/"}
   [junit4]   2> 1024365 T3727 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
   [junit4]   2> 1024367 T3724 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
   [junit4]   2> 1024367 T3722 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
   [junit4]   2> 1024372 T3727 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"state2",
   [junit4]   2> 	  "node_name":"node1",
   [junit4]   2> 	  "core":"core1",
   [junit4]   2> 	  "core_node_name":"node1",
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "numShards":"1",
   [junit4]   2> 	  "base_url":"http://node1/solr/"}
   [junit4]   2> 1024372 T3727 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
   [junit4]   2> 1024373 T3724 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
   [junit4]   2> 1024373 T3722 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
   [junit4]   2> 1024378 T3724 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
   [junit4]   2> 1024378 T3722 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
   [junit4]   2> 1024383 T3727 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"state1",
   [junit4]   2> 	  "node_name":"node1",
   [junit4]   2> 	  "core":"core1",
   [junit4]   2> 	  "core_node_name":"node1",
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "numShards":"1",
   [junit4]   2> 	  "base_url":"http://node1/solr/"}
   [junit4]   2> 1024384 T3727 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
   [junit4]   2> 1024385 T3722 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
   [junit4]   2> 1024385 T3724 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
   [junit4]   2> 1024388 T3727 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
   [junit4]   2> 1024531 T3660 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1024534 T3726 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1024534 T3660 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
   [junit4]   2> 1024537 T3727 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1024538 T3727 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"state2",
   [junit4]   2> 	  "node_name":"node2",
   [junit4]   2> 	  "core":"core4",
   [junit4]   2> 	  "core_node_name":"node2",
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "numShards":"1",
   [junit4]   2> 	  "base_url":"http://node2/solr/"}
   [junit4]   2> 1024538 T3727 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
   [junit4]   2> 1024542 T3726 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1024543 T3724 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
   [junit4]   2> 1024544 T3722 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
   [junit4]   2> 1024551 T3724 oascc.ZkStateReader$3.process Updating live nodes... (1)
   [junit4]   2> 1024552 T3722 oascc.ZkStateReader$3.process Updating live nodes... (1)
   [junit4]   2> 1024555 T3660 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1024555 T3724 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 1024562 T3726 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1024563 T3727 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1024567 T3726 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1024670 T3724 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> 1024757 T3660 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1024759 T3660 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1024760 T3708 oasc.OverseerTest$OverseerRestarter.run Killing overseer.
   [junit4]   2> 1024761 T3730 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1b04d142 name:ZooKeeperConnection Watcher:127.0.0.1:38547/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1024761 T3660 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1024762 T3708 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1024763 T3732 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1af696a7 name:ZooKeeperConnection Watcher:127.0.0.1:38547/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1024763 T3660 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 1024763 T3708 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1024768 T3660 oascc.SolrZkClient.makePath makePath: /live_nodes/node1
   [junit4]   2> 1024769 T3708 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:38547_solr
   [junit4]   2> 1024769 T3708 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
   [junit4]   2> 1024777 T3730 oascc.ZkStateReader$3.process Updating live nodes... (2)
   [junit4]   2> 1024777 T3708 oasc.Overseer.start Overseer (id=91367693046513675-127.0.0.1:38547_solr-n_0000000003) starting
   [junit4]   2> 1024777 T3724 oascc.ZkStateReader$3.process Updating live nodes... (2)
   [junit4]   2> 1024781 T3660 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
   [junit4]   2> 1024786 T3734 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
   [junit4]   2> 1024789 T3734 oasc.OverseerCollectionProcessor.prioritizeOverseerNodes prioritizing overseer nodes
   [junit4]   2> 1024789 T3733 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
   [junit4]   2> 1024794 T3733 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1024795 T3724 oascc.ZkStateReader$3.process Updating live nodes... (1)
   [junit4]   2> 1024795 T3730 oascc.ZkStateReader$3.process Updating live nodes... (1)
   [junit4]   2> 1024800 T3733 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"state1",
   [junit4]   2> 	  "node_name":"node1",
   [junit4]   2> 	  "core":"core1",
   [junit4]   2> 	  "core_node_name":"node1",
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "numShards":"1",
   [junit4]   2> 	  "base_url":"http://node1/solr/"}
   [junit4]   2> 1024800 T3733 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
   [junit4]   2> 1024802 T3730 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 1024803 T3732 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1024803 T3660 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
   [junit4]   2> 1024812 T3733 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1024813 T3732 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1024813 T3730 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> 1024814 T3733 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"state2",
   [junit4]   2> 	  "node_name":"node1",
   [junit4]   2> 	  "core":"core1",
   [junit4]   2> 	  "core_node_name":"node1",
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "numShards":"1",
   [junit4]   2> 	  "base_url":"http://node1/solr/"}
   [junit4]   2> 1024814 T3733 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
   [junit4]   2> 1024817 T3660 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1024818 T3736 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1b0581cf name:ZooKeeperConnection Watcher:127.0.0.1:38547/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1024819 T3660 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1024821 T3660 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 1024823 T3732 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1024825 T3660 oascc.SolrZkClient.makePath makePath: /live_nodes/node2
   [junit4]   2> 1024828 T3736 oascc.ZkStateReader$3.process Updating live nodes... (2)
   [junit4]   2> 1024829 T3730 oascc.ZkStateReader$3.process Updating live nodes... (2)
   [junit4]   2> 1024837 T3732 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1024837 T3660 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
   [junit4]   2> 1024840 T3733 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"state1",
   [junit4]   2> 	  "node_name":"node1",
   [junit4]   2> 	  "core":"core1",
   [junit4]   2> 	  "core_node_name":"node1",
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "numShards":"1",
   [junit4]   2> 	  "base_url":"http://node1/solr/"}
   [junit4]   2> 1024840 T3733 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
   [junit4]   2> 1024844 T3732 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1024850 T3660 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1024948 T3730 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
   [junit4]   2> 1024949 T3736 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
   [junit4]   2> 1025053 T3660 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1025056 T3732 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1025056 T3660 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
   [junit4]   2> 1025056 T3732 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1025057 T3732 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1025059 T3733 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1025060 T3733 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"state2",
   [junit4]   2> 	  "node_name":"node2",
   [junit4]   2> 	  "core":"core4",
   [junit4]   2> 	  "core_node_name":"node2",
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "numShards":"1",
   [junit4]   2> 	  "base_url":"http://node2/solr/"}
   [junit4]   2> 1025060 T3733 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
   [junit4]   2> 1025064 T3732 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1025069 T3736 oascc.ZkStateReader$3.process Updating live nodes... (1)
   [junit4]   2> 1025069 T3730 oascc.ZkStateReader$3.process Updating live nodes... (1)
   [junit4]   2> 1025071 T3660 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1025072 T3736 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 1025079 T3732 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1025083 T3732 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1025186 T3736 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> 1025273 T3660 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1025275 T3660 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1025276 T3738 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1b066934 name:ZooKeeperConnection Watcher:127.0.0.1:38547/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1025276 T3660 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1025278 T3660 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 1025281 T3660 oascc.SolrZkClient.makePath makePath: /live_nodes/node1
   [junit4]   2> 1025286 T3736 oascc.ZkStateReader$3.process Updating live nodes... (2)
   [junit4]   2> 1025286 T3738 oascc.ZkStateReader$3.process Updating live nodes... (2)
   [junit4]   2> 1025287 T3708 oasc.OverseerTest$OverseerRestarter.run Killing overseer.
   [junit4]   2> 1025288 T3708 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1025289 T3740 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1af34207 name:ZooKeeperConnection Watcher:127.0.0.1:38547/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1025290 T3660 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
   [junit4]   2> 1025290 T3708 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1025296 T3708 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:38547_solr
   [junit4]   2> 1025296 T3708 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
   [junit4]   2> 1025300 T3708 oasc.Overseer.start Overseer (id=91367693046513678-127.0.0.1:38547_solr-n_0000000004) starting
   [junit4]   2> 1025303 T3738 oascc.ZkStateReader$3.process Updating live nodes... (1)
   [junit4]   2> 1025304 T3736 oascc.ZkStateReader$3.process Updating live nodes... (1)
   [junit4]   2> 1025308 T3738 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 1025311 T3660 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
   [junit4]   2> 1025312 T3742 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
   [junit4]   2> 1025314 T3742 oasc.OverseerCollectionProcessor.prioritizeOverseerNodes prioritizing overseer nodes
   [junit4]   2> 1025317 T3741 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
   [junit4]   2> 1025320 T3740 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1025322 T3741 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1025323 T3741 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"state1",
   [junit4]   2> 	  "node_name":"node1",
   [junit4]   2> 	  "core":"core1",
   [junit4]   2> 	  "core_node_name":"node1",
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "numShards":"1",
   [junit4]   2> 	  "base_url":"http://node1/solr/"}
   [junit4]   2> 1025323 T3741 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
   [junit4]   2> 1025325 T3660 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1025326 T3744 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1b0717ce name:ZooKeeperConnection Watcher:127.0.0.1:38547/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1025327 T3660 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1025328 T3738 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> 1025330 T3660 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 1025335 T3660 oascc.SolrZkClient.makePath makePath: /live_nodes/node2
   [junit4]   2> 1025336 T3741 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1025337 T3741 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"state2",
   [junit4]   2> 	  "node_name":"node1",
   [junit4]   2> 	  "core":"core1",
   [junit4]   2> 	  "core_node_name":"node1",
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "numShards":"1",
   [junit4]   2> 	  "base_url":"http://node1/solr/"}
   [junit4]   2> 1025337 T3741 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
   [junit4]   2> 1025339 T3738 oascc.ZkStateReader$3.process Updating live nodes... (2)
   [junit4]   2> 1025341 T3744 oascc.ZkStateReader$3.process Updating live nodes... (2)
   [junit4]   2> 1025343 T3740 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1025343 T3660 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
   [junit4]   2> 1025355 T3740 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1025358 T3741 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"state1",
   [junit4]   2> 	  "node_name":"node1",
   [junit4]   2> 	  "core":"core1",
   [junit4]   2> 	  "core_node_name":"node1",
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "numShards":"1",
   [junit4]   2> 

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

 SyncConnected type NodeChildrenChanged
   [junit4]   2> 1062926 T4136 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1062927 T4136 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> 1062927 T4136 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
   [junit4]   2> 1062928 T4136 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard3
   [junit4]   2> 1062931 T4135 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1063034 T4139 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> 1063034 T4133 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> 1063424 T3660 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard3/election
   [junit4]   2> 1063435 T4139 oascc.ZkStateReader$3.process Updating live nodes... (0)
   [junit4]   2> 1063438 T3660 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:55286 55286
   [junit4]   2> 1063622 T3660 oas.SolrTestCaseJ4.tearDown ###Ending testShardAssignment
   [junit4]   1> client port:0.0.0.0/0.0.0.0:0
   [junit4]   2> 1063625 T3660 oas.SolrTestCaseJ4.initCore ####initCore
   [junit4]   2> 1063625 T3660 oas.SolrTestCaseJ4.initCore ####initCore end
   [junit4]   2> 1064936 T4139 oasc.LeaderElector$1.process WARN  org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /collections/collection1/leader_elect/shard3/election
   [junit4]   2> 	at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
   [junit4]   2> 	at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
   [junit4]   2> 	at org.apache.zookeeper.ZooKeeper.getChildren(ZooKeeper.java: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> 1064937 T4139 oasc.LeaderElector$1.process WARN  org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /collections/collection1/leader_elect/shard2/election
   [junit4]   2> 	at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
   [junit4]   2> 	at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
   [junit4]   2> 	at org.apache.zookeeper.ZooKeeper.getChildren(ZooKeeper.java: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> 1064938 T4139 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> 1066626 T3660 oas.SolrTestCaseJ4.deleteCore ###deleteCore
   [junit4]   2> NOTE: test params are: codec=Lucene46: {}, docValues:{}, sim=DefaultSimilarity, locale=el, timezone=Europe/Athens
   [junit4]   2> NOTE: Linux 3.8.0-36-generic i386/Oracle Corporation 1.6.0_45 (32-bit)/cpus=8,threads=1,free=119008640,total=454926336
   [junit4]   2> NOTE: All tests run in this JVM: [TestCollationFieldDocValues, FastVectorHighlighterTest, SchemaVersionSpecificBehaviorTest, TermVectorComponentTest, QueryResultKeyTest, TriLevelCompositeIdRoutingTest, StressHdfsTest, UnloadDistributedZkTest, LukeRequestHandlerTest, SpatialFilterTest, SolrCoreTest, DocumentBuilderTest, UpdateRequestProcessorFactoryTest, TestFileDictionaryLookup, TestFunctionQuery, RecoveryZkTest, AutoCommitTest, TestShardHandlerFactory, TestLRUCache, SuggesterFSTTest, DocValuesMissingTest, AssignTest, DocValuesTest, TestSolrQueryParser, HdfsWriteToMultipleCollectionsTest, TestBadConfig, TestDistributedMissingSort, AnalysisAfterCoreReloadTest, TestSolrDeletionPolicy1, SolrTestCaseJ4Test, ExternalFileFieldSortTest, SoftAutoCommitTest, TestQueryUtils, DistributedSpellCheckComponentTest, BadComponentTest, ClusterStateUpdateTest, ResponseLogComponentTest, SuggesterTest, DateMathParserTest, CacheHeaderTest, TestStandardQParsers, BasicDistributedZkTest, TestBM25SimilarityFactory, TestWriterPerf, TestExceedMaxTermLength, PreAnalyzedUpdateProcessorTest, TestCollationKeyRangeQueries, MBeansHandlerTest, DeleteInactiveReplicaTest, CopyFieldTest, TestNonNRTOpen, TestFieldCollectionResource, LeaderElectionTest, SynonymTokenizerTest, CSVRequestHandlerTest, TestSimpleQParserPlugin, SyncSliceTest, ShowFileRequestHandlerTest, TestFieldResource, TestFaceting, TestSolrQueryParserResource, TestManagedSchema, SliceStateUpdateTest, TestNonDefinedSimilarityFactory, BadCopyFieldTest, TestAnalyzeInfixSuggestions, TestCoreContainer, SOLR749Test, DirectUpdateHandlerOptimizeTest, TestManagedSchemaFieldResource, TestLFUCache, TestHighFrequencyDictionaryFactory, DistributedExpandComponentTest, TestLuceneMatchVersion, TermsComponentTest, ZkControllerTest, TestReplicationHandler, ClusterStateTest, HdfsCollectionsAPIDistributedZkTest, QueryParsingTest, InfoHandlerTest, QueryEqualityTest, JsonLoaderTest, ScriptEngineTest, CoreAdminCreateDiscoverTest, TestRandomDVFaceting, TestPerFieldSimilarity, TestPHPSerializedResponseWriter, ChaosMonkeySafeLeaderTest, OverseerTest]
   [junit4] Completed on J0 in 49.85s, 9 tests, 1 error <<< FAILURES!

[...truncated 573 lines...]
BUILD FAILED
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/build.xml:471: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/build.xml:451: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/build.xml:39: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/extra-targets.xml:37: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build.xml:189: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/common-build.xml:490: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/lucene/common-build.xml:1278: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/lucene/common-build.xml:911: There were test failures: 368 suites, 1577 tests, 1 error, 37 ignored (8 assumptions)

Total time: 81 minutes 40 seconds
Build step 'Invoke Ant' marked build as failure
Description set: Java: 32bit/jrockit-jdk1.6.0_45-R28.2.7-4.1.0 -XnoOpt
Archiving artifacts
Recording test results
Email was triggered for: Failure
Sending email for trigger: Failure



Mime
View raw message