You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@lucene.apache.org by Policeman Jenkins Server <je...@thetaphi.de> on 2014/07/13 14:44:25 UTC

[JENKINS] Lucene-Solr-trunk-MacOSX (64bit/jdk1.7.0) - Build # 1708 - Still Failing!

Build: http://jenkins.thetaphi.de/job/Lucene-Solr-trunk-MacOSX/1708/
Java: 64bit/jdk1.7.0 -XX:+UseCompressedOops -XX:+UseSerialGC

2 tests failed.
REGRESSION:  org.apache.solr.cloud.HttpPartitionTest.testDistribSearch

Error Message:
Expected 2 of 3 replicas to be active but only found 1; [core_node1:{"state":"active","base_url":"http://127.0.0.1:52223","core":"c8n_1x3_lf_shard1_replica2","node_name":"127.0.0.1:52223_","leader":"true"}]; clusterState: live nodes:[127.0.0.1:52219_, 127.0.0.1:52223_] collections:{control_collection=DocCollection(control_collection)={   "autoCreated":"true",   "maxShardsPerNode":"1",   "replicationFactor":"1",   "router":{"name":"compositeId"},   "shards":{"shard1":{       "range":"80000000-7fffffff",       "state":"active",       "replicas":{"core_node1":{           "state":"down",           "base_url":"http://127.0.0.1:52214",           "core":"collection1",           "node_name":"127.0.0.1:52214_",           "leader":"true"}}}}}, collection1=DocCollection(collection1)={   "autoCreated":"true",   "maxShardsPerNode":"1",   "replicationFactor":"1",   "router":{"name":"compositeId"},   "shards":{     "shard1":{       "range":"80000000-ffffffff",       "state":"active",       "replicas":{"core_node1":{           "state":"active",           "base_url":"http://127.0.0.1:52219",           "core":"collection1",           "node_name":"127.0.0.1:52219_",           "leader":"true"}}},     "shard2":{       "range":"0-7fffffff",       "state":"active",       "replicas":{"core_node2":{           "state":"active",           "base_url":"http://127.0.0.1:52223",           "core":"collection1",           "node_name":"127.0.0.1:52223_",           "leader":"true"}}}}}, c8n_1x2=DocCollection(c8n_1x2)={   "maxShardsPerNode":"1",   "replicationFactor":"2",   "router":{"name":"compositeId"},   "shards":{"shard1":{       "range":"80000000-7fffffff",       "state":"active",       "replicas":{         "core_node1":{           "state":"active",           "base_url":"http://127.0.0.1:52219",           "core":"c8n_1x2_shard1_replica1",           "node_name":"127.0.0.1:52219_",           "leader":"true"},         "core_node2":{           "state":"down",           "base_url":"http://127.0.0.1:52214",           "core":"c8n_1x2_shard1_replica2",           "node_name":"127.0.0.1:52214_"}}}}}, c8n_1x3=DocCollection(c8n_1x3)={   "maxShardsPerNode":"1",   "replicationFactor":"3",   "router":{"name":"compositeId"},   "shards":{"shard1":{       "range":"80000000-7fffffff",       "state":"active",       "replicas":{         "core_node1":{           "state":"active",           "base_url":"http://127.0.0.1:52219",           "core":"c8n_1x3_shard1_replica1",           "node_name":"127.0.0.1:52219_"},         "core_node2":{           "state":"active",           "base_url":"http://127.0.0.1:52223",           "core":"c8n_1x3_shard1_replica2",           "node_name":"127.0.0.1:52223_",           "leader":"true"},         "core_node3":{           "state":"down",           "base_url":"http://127.0.0.1:52214",           "core":"c8n_1x3_shard1_replica3",           "node_name":"127.0.0.1:52214_"}}}}}, c8n_1x3_lf=DocCollection(c8n_1x3_lf)={   "maxShardsPerNode":"1",   "replicationFactor":"3",   "router":{"name":"compositeId"},   "shards":{"shard1":{       "range":"80000000-7fffffff",       "state":"active",       "replicas":{         "core_node1":{           "state":"active",           "base_url":"http://127.0.0.1:52223",           "core":"c8n_1x3_lf_shard1_replica2",           "node_name":"127.0.0.1:52223_",           "leader":"true"},         "core_node2":{           "state":"down",           "base_url":"http://127.0.0.1:52219",           "core":"c8n_1x3_lf_shard1_replica1",           "node_name":"127.0.0.1:52219_"},         "core_node3":{           "state":"down",           "base_url":"http://127.0.0.1:52214",           "core":"c8n_1x3_lf_shard1_replica3",           "node_name":"127.0.0.1:52214_"}}}}}}

Stack Trace:
java.lang.AssertionError: Expected 2 of 3 replicas to be active but only found 1; [core_node1:{"state":"active","base_url":"http://127.0.0.1:52223","core":"c8n_1x3_lf_shard1_replica2","node_name":"127.0.0.1:52223_","leader":"true"}]; clusterState: live nodes:[127.0.0.1:52219_, 127.0.0.1:52223_] collections:{control_collection=DocCollection(control_collection)={
  "autoCreated":"true",
  "maxShardsPerNode":"1",
  "replicationFactor":"1",
  "router":{"name":"compositeId"},
  "shards":{"shard1":{
      "range":"80000000-7fffffff",
      "state":"active",
      "replicas":{"core_node1":{
          "state":"down",
          "base_url":"http://127.0.0.1:52214",
          "core":"collection1",
          "node_name":"127.0.0.1:52214_",
          "leader":"true"}}}}}, collection1=DocCollection(collection1)={
  "autoCreated":"true",
  "maxShardsPerNode":"1",
  "replicationFactor":"1",
  "router":{"name":"compositeId"},
  "shards":{
    "shard1":{
      "range":"80000000-ffffffff",
      "state":"active",
      "replicas":{"core_node1":{
          "state":"active",
          "base_url":"http://127.0.0.1:52219",
          "core":"collection1",
          "node_name":"127.0.0.1:52219_",
          "leader":"true"}}},
    "shard2":{
      "range":"0-7fffffff",
      "state":"active",
      "replicas":{"core_node2":{
          "state":"active",
          "base_url":"http://127.0.0.1:52223",
          "core":"collection1",
          "node_name":"127.0.0.1:52223_",
          "leader":"true"}}}}}, c8n_1x2=DocCollection(c8n_1x2)={
  "maxShardsPerNode":"1",
  "replicationFactor":"2",
  "router":{"name":"compositeId"},
  "shards":{"shard1":{
      "range":"80000000-7fffffff",
      "state":"active",
      "replicas":{
        "core_node1":{
          "state":"active",
          "base_url":"http://127.0.0.1:52219",
          "core":"c8n_1x2_shard1_replica1",
          "node_name":"127.0.0.1:52219_",
          "leader":"true"},
        "core_node2":{
          "state":"down",
          "base_url":"http://127.0.0.1:52214",
          "core":"c8n_1x2_shard1_replica2",
          "node_name":"127.0.0.1:52214_"}}}}}, c8n_1x3=DocCollection(c8n_1x3)={
  "maxShardsPerNode":"1",
  "replicationFactor":"3",
  "router":{"name":"compositeId"},
  "shards":{"shard1":{
      "range":"80000000-7fffffff",
      "state":"active",
      "replicas":{
        "core_node1":{
          "state":"active",
          "base_url":"http://127.0.0.1:52219",
          "core":"c8n_1x3_shard1_replica1",
          "node_name":"127.0.0.1:52219_"},
        "core_node2":{
          "state":"active",
          "base_url":"http://127.0.0.1:52223",
          "core":"c8n_1x3_shard1_replica2",
          "node_name":"127.0.0.1:52223_",
          "leader":"true"},
        "core_node3":{
          "state":"down",
          "base_url":"http://127.0.0.1:52214",
          "core":"c8n_1x3_shard1_replica3",
          "node_name":"127.0.0.1:52214_"}}}}}, c8n_1x3_lf=DocCollection(c8n_1x3_lf)={
  "maxShardsPerNode":"1",
  "replicationFactor":"3",
  "router":{"name":"compositeId"},
  "shards":{"shard1":{
      "range":"80000000-7fffffff",
      "state":"active",
      "replicas":{
        "core_node1":{
          "state":"active",
          "base_url":"http://127.0.0.1:52223",
          "core":"c8n_1x3_lf_shard1_replica2",
          "node_name":"127.0.0.1:52223_",
          "leader":"true"},
        "core_node2":{
          "state":"down",
          "base_url":"http://127.0.0.1:52219",
          "core":"c8n_1x3_lf_shard1_replica1",
          "node_name":"127.0.0.1:52219_"},
        "core_node3":{
          "state":"down",
          "base_url":"http://127.0.0.1:52214",
          "core":"c8n_1x3_lf_shard1_replica3",
          "node_name":"127.0.0.1:52214_"}}}}}}
	at __randomizedtesting.SeedInfo.seed([BC417A8BC334AEA5:3DA7F493B46BCE99]:0)
	at org.junit.Assert.fail(Assert.java:93)
	at org.junit.Assert.assertTrue(Assert.java:43)
	at org.apache.solr.cloud.HttpPartitionTest.testRf3WithLeaderFailover(HttpPartitionTest.java:367)
	at org.apache.solr.cloud.HttpPartitionTest.doTest(HttpPartitionTest.java:148)
	at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:863)
	at sun.reflect.GeneratedMethodAccessor49.invoke(Unknown Source)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:606)
	at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1618)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:827)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:863)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:877)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
	at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:50)
	at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
	at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:49)
	at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:65)
	at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:365)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:798)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:458)
	at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:836)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:738)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:772)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:783)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
	at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
	at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:42)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
	at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
	at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:43)
	at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
	at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:65)
	at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:55)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:365)
	at java.lang.Thread.run(Thread.java:745)


REGRESSION:  org.apache.solr.cloud.OverseerTest.testOverseerFailure

Error Message:
KeeperErrorCode = NoNode for /collections/collection1/leader_elect/shard1/election

Stack Trace:
org.apache.zookeeper.KeeperException$NoNodeException: KeeperErrorCode = NoNode for /collections/collection1/leader_elect/shard1/election
	at __randomizedtesting.SeedInfo.seed([BC417A8BC334AEA5:B849F578D1914184]:0)
	at org.apache.zookeeper.KeeperException.create(KeeperException.java:111)
	at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
	at org.apache.zookeeper.ZooKeeper.getChildren(ZooKeeper.java:1472)
	at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:260)
	at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:257)
	at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
	at org.apache.solr.common.cloud.SolrZkClient.getChildren(SolrZkClient.java:257)
	at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:94)
	at org.apache.solr.cloud.LeaderElector.joinElection(LeaderElector.java:314)
	at org.apache.solr.cloud.LeaderElector.joinElection(LeaderElector.java:221)
	at org.apache.solr.cloud.OverseerTest$MockZKController.publishState(OverseerTest.java:155)
	at org.apache.solr.cloud.OverseerTest.testOverseerFailure(OverseerTest.java:660)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:606)
	at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1618)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:827)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:863)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:877)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
	at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:50)
	at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
	at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:49)
	at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:65)
	at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:365)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:798)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:458)
	at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:836)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:738)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:772)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:783)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
	at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
	at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:42)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
	at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
	at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:43)
	at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
	at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:65)
	at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:55)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:365)
	at java.lang.Thread.run(Thread.java:745)




Build Log:
[...truncated 11038 lines...]
   [junit4] Suite: org.apache.solr.cloud.OverseerTest
   [junit4]   2> Creating dataDir: /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./temp/solr.cloud.OverseerTest-BC417A8BC334AEA5-001/init-core-data-001
   [junit4]   2> 1144547 T3470 oas.SolrTestCaseJ4.buildSSLConfig Randomized ssl (true) and clientAuth (false)
   [junit4]   2> 1144548 T3470 oas.SolrTestCaseJ4.initCore ####initCore
   [junit4]   2> 1144548 T3470 oas.SolrTestCaseJ4.initCore ####initCore end
   [junit4]   2> 1144554 T3470 oas.SolrTestCaseJ4.setUp ###Starting testShardLeaderChange
   [junit4]   2> 1144555 T3470 oasc.ZkTestServer.run STARTING ZK TEST SERVER
   [junit4]   1> client port:0.0.0.0/0.0.0.0:0
   [junit4]   2> 1144557 T3471 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
   [junit4]   2> 1144657 T3470 oasc.ZkTestServer.run start zk server on port:50149
   [junit4]   2> 1144659 T3470 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1144664 T3477 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@582ddb86 name:ZooKeeperConnection Watcher:127.0.0.1:50149/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1144665 T3470 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1144666 T3470 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1144671 T3479 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@7b7cbf1c name:ZooKeeperConnection Watcher:127.0.0.1:50149 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1144671 T3470 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1144679 T3470 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1144684 T3481 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@5c329526 name:ZooKeeperConnection Watcher:127.0.0.1:50149 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1144685 T3470 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1144685 T3470 oascc.SolrZkClient.makePath makePath: /solr
   [junit4]   2> 1144697 T3470 oascc.SolrZkClient.makePath makePath: /live_nodes
   [junit4]   2> 1144704 T3482 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1144706 T3470 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1144708 T3484 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@31912a68 name:ZooKeeperConnection Watcher:127.0.0.1:50149/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1144709 T3482 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1144709 T3486 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@6b996bb name:ZooKeeperConnection Watcher:127.0.0.1:50149/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1144709 T3470 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1144710 T3482 oascc.SolrZkClient.makePath makePath: /overseer_elect
   [junit4]   2> 1144711 T3470 oascc.SolrZkClient.makePath makePath: /clusterstate.json
   [junit4]   2> 1144716 T3482 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
   [junit4]   2> 1144716 T3470 oascc.SolrZkClient.makePath makePath: /aliases.json
   [junit4]   2> 1144719 T3470 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 1144725 T3482 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:50149_solr
   [junit4]   2> 1144725 T3482 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
   [junit4]   2> 1144727 T3470 oascc.SolrZkClient.makePath makePath: /live_nodes/node1
   [junit4]   2> 1144729 T3482 oasc.Overseer.start Overseer (id=92094605142917123-127.0.0.1:50149_solr-n_0000000000) starting
   [junit4]   2> 1144734 T3470 oascc.SolrZkClient.makePath makePath: /overseer/queue
   [junit4]   2> 1144734 T3482 oascc.SolrZkClient.makePath makePath: /overseer/queue
   [junit4]   2> 1144741 T3482 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
   [junit4]   2> 1144750 T3482 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-failure
   [junit4]   2> 1144757 T3482 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-running
   [junit4]   2> 1144764 T3482 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-completed
   [junit4]   2> 1144772 T3482 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
   [junit4]   2> 1144786 T3482 oasc.OverseerTest$OverseerRestarter.run Killing overseer.
   [junit4]   2> 1144786 T3488 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
   [junit4]   2> 1144790 T3482 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1144793 T3490 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@150ddb85 name:ZooKeeperConnection Watcher:127.0.0.1:50149/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1144793 T3482 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1144794 T3488 oasc.OverseerCollectionProcessor.amILeader According to ZK I (id=92094605142917123-127.0.0.1:50149_solr-n_0000000000) am no longer a leader.
   [junit4]   2> 1144795 T3488 oasc.SolrException.log ERROR :org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /overseer/collection-queue-work
   [junit4]   2> 		at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
   [junit4]   2> 		at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
   [junit4]   2> 		at org.apache.zookeeper.ZooKeeper.getChildren(ZooKeeper.java:1472)
   [junit4]   2> 		at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:260)
   [junit4]   2> 		at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:257)
   [junit4]   2> 		at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
   [junit4]   2> 		at org.apache.solr.common.cloud.SolrZkClient.getChildren(SolrZkClient.java:257)
   [junit4]   2> 		at org.apache.solr.cloud.DistributedQueue.orderedChildren(DistributedQueue.java:99)
   [junit4]   2> 		at org.apache.solr.cloud.DistributedQueue.getTailId(DistributedQueue.java:483)
   [junit4]   2> 		at org.apache.solr.cloud.OverseerCollectionProcessor.run(OverseerCollectionProcessor.java:241)
   [junit4]   2> 		at java.lang.Thread.run(Thread.java:745)
   [junit4]   2> 	
   [junit4]   2> 1144797 T3488 oasc.OverseerCollectionProcessor.run ERROR Unable to prioritize overseer  org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /roles.json
   [junit4]   2> 	at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
   [junit4]   2> 	at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
   [junit4]   2> 	at org.apache.zookeeper.ZooKeeper.exists(ZooKeeper.java:1045)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient$4.execute(SolrZkClient.java:226)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient$4.execute(SolrZkClient.java:223)
   [junit4]   2> 	at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient.exists(SolrZkClient.java:223)
   [junit4]   2> 	at org.apache.solr.cloud.OverseerCollectionProcessor.prioritizeOverseerNodes(OverseerCollectionProcessor.java:412)
   [junit4]   2> 	at org.apache.solr.cloud.OverseerCollectionProcessor.run(OverseerCollectionProcessor.java:256)
   [junit4]   2> 	at java.lang.Thread.run(Thread.java:745)
   [junit4]   2> 
   [junit4]   2> 1144804 T3482 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:50149_solr
   [junit4]   2> 1144805 T3482 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
   [junit4]   2> 1144812 T3482 oasc.Overseer.start Overseer (id=92094605142917125-127.0.0.1:50149_solr-n_0000000001) starting
   [junit4]   2> 1144849 T3492 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
   [junit4]   2> 1144850 T3491 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
   [junit4]   2> 1144856 T3491 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1144858 T3491 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> 1144858 T3491 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1]
   [junit4]   2> 1144858 T3491 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
   [junit4]   2> 1144864 T3490 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1144865 T3486 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> 1145242 T3470 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
   [junit4]   2> 1145294 T3470 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 1145324 T3490 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1145332 T3490 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1145333 T3470 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
   [junit4]   2> 1145333 T3491 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1145347 T3491 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> 1145348 T3491 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
   [junit4]   2> 1145355 T3470 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1145355 T3490 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1145357 T3494 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@39e5046c name:ZooKeeperConnection Watcher:127.0.0.1:50149/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1145358 T3470 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1145362 T3470 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 1145369 T3470 oascc.SolrZkClient.makePath makePath: /live_nodes/node2
   [junit4]   2> 1145379 T3470 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
   [junit4]   2> 1145379 T3490 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1145383 T3491 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> 1145383 T3491 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
   [junit4]   2> 1145388 T3490 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1145394 T3470 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1145496 T3486 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> 1145497 T3494 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> 1145599 T3470 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1145616 T3490 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1145617 T3490 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1145617 T3490 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1145622 T3491 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1145624 T3491 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> 1145624 T3491 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=1
   [junit4]   2> 1145624 T3491 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
   [junit4]   2> 1145629 T3490 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1145738 T3486 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> 1145738 T3494 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> 1146118 T3470 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
   [junit4]   2> 1146169 T3470 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1146171 T3494 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 1146188 T3490 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1146188 T3490 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1146188 T3490 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1146193 T3491 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1146200 T3490 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1146309 T3494 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> 1146374 T3470 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1146379 T3470 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1146389 T3496 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@2a624887 name:ZooKeeperConnection Watcher:127.0.0.1:50149/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1146390 T3470 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1146397 T3470 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 1146414 T3470 oascc.SolrZkClient.makePath makePath: /live_nodes/node1
   [junit4]   2> 1146430 T3490 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1146431 T3490 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1146431 T3490 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1146430 T3470 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
   [junit4]   2> 1146435 T3491 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1146436 T3491 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> 1146437 T3491 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
   [junit4]   2> 1146442 T3490 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1146452 T3496 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 1146454 T3470 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
   [junit4]   2> 1146454 T3490 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1146458 T3491 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> 1146458 T3491 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
   [junit4]   2> 1146465 T3490 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1146472 T3470 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1146473 T3482 oasc.OverseerTest$OverseerRestarter.run Killing overseer.
   [junit4]   2> 1146476 T3490 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1146477 T3498 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@2a289f01 name:ZooKeeperConnection Watcher:127.0.0.1:50149/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1146477 T3470 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1146478 T3482 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1146480 T3500 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@706886c9 name:ZooKeeperConnection Watcher:127.0.0.1:50149/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1146480 T3470 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 1146480 T3482 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1146481 T3491 oasc.Overseer$ClusterStateUpdater.run Overseer Loop exiting : 127.0.0.1:50149_solr
   [junit4]   2> 1146485 T3501 oasc.Overseer$ClusterStateUpdater.checkIfIamStillLeader ERROR could not read the data org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /overseer_elect/leader
   [junit4]   2> 	at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
   [junit4]   2> 	at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
   [junit4]   2> 	at org.apache.zookeeper.ZooKeeper.getData(ZooKeeper.java:1155)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:277)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:274)
   [junit4]   2> 	at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient.getData(SolrZkClient.java:274)
   [junit4]   2> 	at org.apache.solr.cloud.Overseer$ClusterStateUpdater.checkIfIamStillLeader(Overseer.java:317)
   [junit4]   2> 	at org.apache.solr.cloud.Overseer$ClusterStateUpdater.access$300(Overseer.java:85)
   [junit4]   2> 	at org.apache.solr.cloud.Overseer$ClusterStateUpdater$1.run(Overseer.java:289)
   [junit4]   2> 
   [junit4]   2> 1146490 T3470 oascc.SolrZkClient.makePath makePath: /live_nodes/node2
   [junit4]   2> 1146492 T3482 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:50149_solr
   [junit4]   2> 1146492 T3482 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
   [junit4]   2> 1146499 T3482 oasc.Overseer.start Overseer (id=92094605142917129-127.0.0.1:50149_solr-n_0000000002) starting
   [junit4]   2> 1146500 T3470 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
   [junit4]   2> 1146515 T3470 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1146525 T3503 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
   [junit4]   2> 1146530 T3502 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1146531 T3502 oasc.Overseer$ClusterStateUpdater.run Replaying operations from work queue.
   [junit4]   2> 1146532 T3502 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> 1146532 T3502 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
   [junit4]   2> 1146537 T3496 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> 1146538 T3498 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> 1146541 T3502 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> 1146542 T3502 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
   [junit4]   2> 1146544 T3498 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> 1146547 T3496 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> 1146555 T3498 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> 1146558 T3496 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> 1146561 T3502 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
   [junit4]   2> 1146563 T3502 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1146564 T3502 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> 1146565 T3502 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
   [junit4]   2> 1146570 T3500 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1146677 T3498 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> 1146678 T3496 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> 1146720 T3470 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1146731 T3470 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
   [junit4]   2> 1146731 T3500 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1146732 T3500 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1146733 T3500 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1146737 T3502 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1146739 T3502 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> 1146739 T3502 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
   [junit4]   2> 1146744 T3500 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1146751 T3470 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1146752 T3498 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 1146764 T3500 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1146771 T3500 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1146881 T3498 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> 1146956 T3470 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1146961 T3470 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1146963 T3505 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@4b242bd3 name:ZooKeeperConnection Watcher:127.0.0.1:50149/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1146964 T3470 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1146966 T3470 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 1146973 T3470 oascc.SolrZkClient.makePath makePath: /live_nodes/node1
   [junit4]   2> 1146985 T3500 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1146985 T3500 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1146986 T3500 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1146985 T3470 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
   [junit4]   2> 1146990 T3502 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1146992 T3502 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> 1146992 T3502 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
   [junit4]   2> 1146997 T3500 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1147008 T3505 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 1147009 T3470 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
   [junit4]   2> 1147010 T3500 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1147013 T3502 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> 1147013 T3502 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
   [junit4]   2> 1147019 T3500 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1147022 T3500 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1147030 T3470 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1147031 T3482 oasc.OverseerTest$OverseerRestarter.run Killing overseer.
   [junit4]   2> 1147033 T3500 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1147036 T3507 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@6b54313f name:ZooKeeperConnection Watcher:127.0.0.1:50149/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1147036 T3470 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1147041 T3482 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1147044 T3470 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 1147045 T3509 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@737bb199 name:ZooKeeperConnection Watcher:127.0.0.1:50149/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1147045 T3482 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1147045 T3502 oasc.Overseer$ClusterStateUpdater.run Overseer Loop exiting : 127.0.0.1:50149_solr
   [junit4]   2> 1147049 T3510 oasc.Overseer$ClusterStateUpdater.checkIfIamStillLeader ERROR could not read the data org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /overseer_elect/leader
   [junit4]   2> 	at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
   [junit4]   2> 	at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
   [junit4]   2> 	at org.apache.zookeeper.ZooKeeper.getData(ZooKeeper.java:1155)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:277)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:274)
   [junit4]   2> 	at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient.getData(SolrZkClient.java:274)
   [junit4]   2> 	at org.apache.solr.cloud.Overseer$ClusterStateUpdater.checkIfIamStillLeader(Overseer.java:317)
   [junit4]   2> 	at org.apache.solr.cloud.Overseer$ClusterStateUpdater.access$300(Overseer.java:85)
   [junit4]   2> 	at org.apache.solr.cloud.Overseer$ClusterStateUpdater$1.run(Overseer.java:289)
   [junit4]   2> 
   [junit4]   2> 1147060 T3482 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:50149_solr
   [junit4]   2> 1147061 T3482 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
   [junit4]   2> 1147062 T3470 oascc.SolrZkClient.makePath makePath: /live_nodes/node2
   [junit4]   2> 1147070 T3482 oasc.Overseer.start Overseer (id=92094605142917132-127.0.0.1:50149_solr-n_0000000003) starting
   [junit4]   2> 1147078 T3470 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
   [junit4]   2> 1147104 T3470 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1147104 T3512 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
   [junit4]   2> 1147110 T3511 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1147112 T3511 oasc.Overseer$ClusterStateUpdater.run Replaying operations from work queue.
   [junit4]   2> 1147113 T3511 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> 1147113 T3511 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
   [junit4]   2> 1147115 T3507 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> 1147116 T3505 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> 1147122 T3511 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> 1147123 T3511 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
   [junit4]   2> 1147124 T3507 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> 1147124 T3505 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> 1147131 T3507 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> 1147131 T3505 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> 1147136 T3511 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
   [junit4]   2> 1147141 T3511 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1147142 T3511 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> 1147142 T3511 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
   [junit4]   2> 1147148 T3509 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1147258 T3507 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> 1147259 T3505 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> 1147313 T3470 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1147320 T3470 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
   [junit4]   2> 1147320 T3509 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1147321 T3509 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1147322 T3509 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1147325 T3511 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1147327 T3511 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> 1147327 T3511 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
   [junit4]   2> 1147348 T3509 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1147352 T3470 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1147352 T3507 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 1147364 T3509 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1147371 T3509 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1147481 T3507 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> 1147558 T3470 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1147563 T3470 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1147572 T3514 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@458fe7e name:ZooKeeperConnection Watcher:127.0.0.1:50149/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1147573 T3470 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1147580 T3470 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 1147594 T3470 oascc.SolrZkClient.makePath makePath: /live_nodes/node1
   [junit4]   2> 1147611 T3482 oasc.OverseerTest$OverseerRestarter.run Killing overseer.
   [junit4]   2> 1147620 T3482 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1147624 T3470 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
   [junit4]   2> 1147629 T3516 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@107c2352 name:ZooKeeperConnection Watcher:127.0.0.1:50149/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1147630 T3482 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1147631 T3511 oasc.Overseer$ClusterStateUpdater.run Overseer Loop exiting : 127.0.0.1:50149_solr
   [junit4]   2> 1147634 T3517 oasc.Overseer$ClusterStateUpdater.checkIfIamStillLeader ERROR could not read the data org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /overseer_elect/leader
   [junit4]   2> 	at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
   [junit4]   2> 	at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
   [junit4]   2> 	at org.apache.zookeeper.ZooKeeper.getData(ZooKeeper.java:1155)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:277)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:274)
   [junit4]   2> 	at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient.getData(SolrZkClient.java:274)
   [junit4]   2> 	at org.apache.solr.cloud.Overseer$ClusterStateUpdater.checkIfIamStillLeader(Overseer.java:317)
   [junit4]   2> 	at org.apache.solr.cloud.Overseer$ClusterStateUpdater.access$300(Overseer.java:85)
   [junit4]   2> 	at org.apache.solr.cloud.Overseer$ClusterStateUpdater$1.run(Overseer.java:289)
   [junit4]   2> 
   [junit4]   2> 1147640 T3482 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:50149_solr
   [junit4]   2> 1147640 T3482 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
   [junit4]   2> 1147645 T3482 oasc.Overseer.start Overseer (id=92094605142917134-127.0.0.1:50149_solr-n_0000000004) starting
   [junit4]   2> 1147652 T3514 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 1147654 T3470 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
   [junit4]   2> 1147662 T3486 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
   [junit4]   2> 1147662 T3486 oasc.LeaderElector$ElectionWatcher.process WARN  org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /collections/collection1/leader_elect/shard1/election
   [junit4]   2> 	at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
   [junit4]   2> 	at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
   [junit4]   2> 	at org.apache.zookeeper.ZooKeeper.getChildren(ZooKeeper.java:1472)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:260)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:257)
   [junit4]   2> 	at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient.getChildren(SolrZkClient.java:257)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:94)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector.access$200(LeaderElector.java:55)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector$ElectionWatcher.process(LeaderElector.java:358)
   [junit4]   2> 	at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:522)
   [junit4]   2> 	at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:498)
   [junit4]   2> 
   [junit4]   2> 1147663 T3486 oasc.LeaderElector$ElectionWatcher.process WARN  org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /collections/collection1/leader_elect/shard1/election
   [junit4]   2> 	at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
   [junit4]   2> 	at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
   [junit4]   2> 	at org.apache.zookeeper.ZooKeeper.getChildren(ZooKeeper.java:1472)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:260)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:257)
   [junit4]   2> 	at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient.getChildren(SolrZkClient.java:257)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:94)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector.access$200(LeaderElector.java:55)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector$ElectionWatcher.process(LeaderElector.java:358)
   [junit4]   2> 	at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:522)
   [junit4]   2> 	at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:498)
   [junit4]   2> 
   [junit4]   2> 1147672 T3470 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1147675 T3520 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@620ea738 name:ZooKeeperConnection Watcher:127.0.0.1:50149/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1147675 T3470 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1147678 T3470 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 1147679 T3521 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
   [junit4]   2> 1147681 T3518 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
   [junit4]   2> 1147685 T3470 oascc.SolrZkClient.makePath makePath: /live_nodes/node2
   [junit4]   2> 1147687 T3518 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1147688 T3518 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> 1147689 T3518 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
   [junit4]   2> 1147695 T3516 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1147695 T3470 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
   [junit4]   2> 1147697 T3514 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> 1147697 T3520 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> 1147707 T3518 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1147708 T3518 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> 1147708 T3518 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
   [junit4]   2> 1147712 T3516 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1147714 T3470 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1147719 T3516 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1147722 T3518 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> 1147722 T3518 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
   [junit4]   2> 1147728 T3516 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1147837 T3514 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> 1147837 T3520 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> 1147919 T3470 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1147933 T3516 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1147934 T3516 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1147935 T3516 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1147933 T3470 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
   [junit4]   2> 1147944 T3518 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1147948 T3518 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> 1147948 T3518 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
   [junit4]   2> 1147953 T3516 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1147961 T3470 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1147962 T3520 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 1147972 T3516 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1147980 T3516 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1148090 T3520 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> 1148168 T3470 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1148204 T3470 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:50149 50149
   [junit4]   2> 1148235 T3471 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:50149 50149
   [junit4]   2> 1148251 T3496 oasc.LeaderElector$ElectionWatcher.process WARN  org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /collections/collection1/leader_elect/shard1/election
   [junit4]   2> 	at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
   [junit4]   2> 	at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
   [junit4]   2> 	at org.apache.zookeeper.ZooKeeper.getChildren(ZooKeeper.java:1472)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:260)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:257)
   [junit4]   2> 	at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient.getChildren(SolrZkClient.java:257)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:94)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector.access$200(LeaderElector.java:55)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector$ElectionWatcher.process(LeaderElector.java:358)
   [junit4]   2> 	at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:522)
   [junit4]   2> 	at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:498)
   [junit4]   2> 
   [junit4]   2> 1148253 T3496 oasc.LeaderElector$ElectionWatcher.process WARN  org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /collections/collection1/leader_elect/shard1/election
   [junit4]   2> 	at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
   [junit4]   2> 	at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
   [junit4]   2> 	at org.apache.zookeeper.ZooKeeper.getChildren(ZooKeeper.java:1472)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:260)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:257)
   [junit4]   2> 	at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient.getChildren(SolrZkClient.java:257)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:94)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector.access$200(LeaderElector.java:55)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector$ElectionWatcher.process(LeaderElector.java:358)
   [junit4]   2> 	at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:522)
   [junit4]   2> 	at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:498)
   [junit4]   2> 
   [junit4]   2> 1148520 T3470 oas.SolrTestCaseJ4.tearDown ###Ending testShardLeaderChange
   [junit4]   2> 1148527 T3518 oasc.Overseer$ClusterStateUpdater.run Overseer Loop exiting : 127.0.0.1:50149_solr
   [junit4]   2> 1148528 T3522 oasc.Overseer$ClusterStateUpdater.checkIfIamStillLeader ERROR could not read the data org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /overseer_elect/leader
   [junit4]   2> 	at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
   [junit4]   2> 	at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
   [junit4]   2> 	at org.apache.zookeeper.ZooKeeper.getData(ZooKeeper.java:1155)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:277)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:274)
   [junit4]   2> 	at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient.getData(SolrZkClient.java:274)
   [junit4]   2> 	at org.apache.solr.cloud.Overseer$ClusterStateUpdater.checkIfIamStillLeader(Overseer.java:317)
   [junit4]   2> 	at org.apache.solr.cloud.Overseer$ClusterStateUpdater.access$300(Overseer.java:85)
   [junit4]   2> 	at org.apache.solr.cloud.Overseer$ClusterStateUpdater$1.run(Overseer.java:289)
   [junit4]   2> 
   [junit4]   2> 1148537 T3470 oas.SolrTestCaseJ4.setUp ###Starting testShardAssignmentBigger
   [junit4]   2> 1148538 T3470 oasc.ZkTestServer.run STARTING ZK TEST SERVER
   [junit4]   1> client port:0.0.0.0/0.0.0.0:0
   [junit4]   2> 1148540 T3523 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
   [junit4]   2> 1148642 T3470 oasc.ZkTestServer.run start zk server on port:50166
   [junit4]   2> 1148644 T3470 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1148654 T3529 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@bb99169 name:ZooKeeperConnection Watcher:127.0.0.1:50166 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1148660 T3470 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1148666 T3470 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1148668 T3531 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@4109c9e1 name:ZooKeeperConnection Watcher:127.0.0.1:50166 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1148669 T3470 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1148669 T3470 oascc.SolrZkClient.makePath makePath: /solr
   [junit4]   2> 1148677 T3470 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1148680 T3533 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@70f4b017 name:ZooKeeperConnection Watcher:127.0.0.1:50166/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1148681 T3470 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1148682 T3470 oascc.SolrZkClient.makePath makePath: /live_nodes
   [junit4]   2> 1148686 T3470 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1148689 T3535 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@38390ab6 name:ZooKeeperConnection Watcher:127.0.0.1:50166/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1148689 T3470 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1148691 T3470 oascc.SolrZkClient.makePath makePath: /overseer_elect
   [junit4]   2> 1148696 T3470 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
   [junit4]   2> 1148706 T3470 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:50166_solr
   [junit4]   2> 1148706 T3470 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
   [junit4]   2> 1148712 T3470 oasc.Overseer.start Overseer (id=92094605403947011-127.0.0.1:50166_solr-n_0000000000) starting
   [junit4]   2> 1148717 T3470 oascc.SolrZkClient.makePath makePath: /overseer/queue
   [junit4]   2> 1148725 T3470 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
   [junit4]   2> 1148736 T3470 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-failure
   [junit4]   2> 1148745 T3470 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-running
   [junit4]   2> 1148753 T3470 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-completed
   [junit4]   2> 1148765 T3470 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
   [junit4]   2> 1148784 T3537 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
   [junit4]   2> 1148785 T3470 oascc.SolrZkClient.makePath makePath: /clusterstate.json
   [junit4]   2> 1148788 T3536 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
   [junit4]   2> 1148793 T3470 oascc.SolrZkClient.makePath makePath: /aliases.json
   [junit4]   2> 1148802 T3470 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 1148820 T3470 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1148823 T3539 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@529caeff name:ZooKeeperConnection Watcher:127.0.0.1:50166/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1148823 T3470 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1148825 T3470 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 1148833 T3470 oascc.SolrZkClient.makePath makePath: /live_nodes/node0
   [junit4]   2> 1148841 T3470 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1148843 T3541 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1f46742f name:ZooKeeperConnection Watcher:127.0.0.1:50166/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1148844 T3470 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1148847 T3470 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 1148853 T3505 oasc.LeaderElector$ElectionWatcher.process WARN  org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /collections/collection1/leader_elect/shard1/election
   [junit4]   2> 	at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
   [junit4]   2> 	at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
   [junit4]   2> 	at org.apache.zookeeper.ZooKeeper.getChildren(ZooKeeper.java:1472)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:260)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:257)
   [junit4]   2> 	at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient.getChildren(SolrZkClient.java:257)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:94)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector.access$200(LeaderElector.java:55)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector$ElectionWatcher.process(LeaderElector.java:358)
   [junit4]   2> 	at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:522)
   [junit4]   2> 	at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:498)
   [junit4]   2> 
   [junit4]   2> 1148853 T3505 oasc.LeaderElector$ElectionWatcher.process WARN  org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /collections/collection1/leader_elect/shard1/election
   [junit4]   2> 	at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
   [junit4]   2> 	at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
   [junit4]   2> 	at org.apache.zookeeper.ZooKeeper.getChildren(ZooKeeper.java:1472)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:260)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:257)
   [junit4]   2> 	at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient.getChildren(SolrZkClient.java:257)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:94)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector.access$200(LeaderElector.java:55)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector$ElectionWatcher.process(LeaderElector.java:358)
   [junit4]   2> 	at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:522)
   [junit4]   2> 	at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:498)
   [junit4]   2> 
   [junit4]   2> 1148853 T3470 oascc.SolrZkClient.makePath makePath: /live_nodes/node1
   [junit4]   2> 1148861 T3470 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1148863 T3543 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@659f329e name:ZooKeeperConnection Watcher:127.0.0.1:50166/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1148863 T3470 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1148866 T3470 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 1148872 T3470 oascc.SolrZkClient.makePath makePath: /live_nodes/node2
   [junit4]   2> 1148879 T3470 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1148881 T3545 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@687684b7 name:ZooKeeperConnection Watcher:127.0.0.1:50166/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1148882 T3470 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1148884 T3470 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 1148890 T3470 oascc.SolrZkClient.makePath makePath: /live_nodes/node3
   [junit4]   2> 1148897 T3470 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1148899 T3547 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@760d0ad6 name:ZooKeeperConnection Watcher:127.0.0.1:50166/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1148899 T3470 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1148902 T3470 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 1148909 T3470 oascc.SolrZkClient.makePath makePath: /live_nodes/node4
   [junit4]   2> 1148917 T3470 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1148920 T3549 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@4e25710e name:ZooKeeperConnection Watcher:127.0.0.1:50166/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1148921 T347

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

che.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient.getData(SolrZkClient.java:274)
   [junit4]   2> 	at org.apache.solr.cloud.Overseer$ClusterStateUpdater.checkIfIamStillLeader(Overseer.java:317)
   [junit4]   2> 	at org.apache.solr.cloud.Overseer$ClusterStateUpdater.access$300(Overseer.java:85)
   [junit4]   2> 	at org.apache.solr.cloud.Overseer$ClusterStateUpdater$1.run(Overseer.java:289)
   [junit4]   2> 
   [junit4]   2> NOTE: test params are: codec=Lucene49: {timestamp=PostingsFormat(name=SimpleText), id=PostingsFormat(name=Memory doPackFST= false), multiDefault=PostingsFormat(name=SimpleText), intDefault=Pulsing41(freqCutoff=12 minBlockSize=68 maxBlockSize=152), text=PostingsFormat(name=NestedPulsing), range_facet_l=PostingsFormat(name=SimpleText), a_t=PostingsFormat(name=SimpleText), _version_=Pulsing41(freqCutoff=12 minBlockSize=68 maxBlockSize=152)}, docValues:{timestamp=DocValuesFormat(name=Lucene49)}, sim=DefaultSimilarity, locale=uk, timezone=America/Porto_Velho
   [junit4]   2> NOTE: Mac OS X 10.8.5 x86_64/Oracle Corporation 1.7.0_60 (64-bit)/cpus=2,threads=1,free=176269416,total=395743232
   [junit4]   2> NOTE: All tests run in this JVM: [JsonLoaderTest, TestManagedStopFilterFactory, TestIBSimilarityFactory, BasicDistributedZkTest, DirectSolrSpellCheckerTest, TestGroupingSearch, DateRangeFieldTest, TestWordDelimiterFilterFactory, AnalyticsQueryTest, TestHighlightDedupGrouping, TestMissingGroups, HdfsChaosMonkeySafeLeaderTest, BinaryUpdateRequestHandlerTest, DateFieldTest, OverseerCollectionProcessorTest, QueryElevationComponentTest, SolrIndexSplitterTest, SearchHandlerTest, AlternateDirectoryTest, TestFastOutputStream, StatsComponentTest, BadCopyFieldTest, CoreAdminRequestStatusTest, TestSolr4Spatial, DistributedDebugComponentTest, TestSuggestSpellingConverter, TestSolrIndexConfig, SuggestComponentTest, TestComplexPhraseQParserPlugin, AliasIntegrationTest, SolrXmlInZkTest, HdfsLockFactoryTest, CollectionsAPIDistributedZkTest, SpellCheckComponentTest, TestSolrXml, TestRangeQuery, TestFoldingMultitermQuery, LeaderElectionTest, MoreLikeThisHandlerTest, CachingDirectoryFactoryTest, HardAutoCommitTest, ResourceLoaderTest, DirectUpdateHandlerTest, DistributedTermsComponentTest, MultiTermTest, TestCopyFieldCollectionResource, QueryParsingTest, TestRandomFaceting, SimplePostToolTest, TestCloudManagedSchema, TestReloadAndDeleteDocs, TestSolrXmlPersistor, TestDistributedMissingSort, SOLR749Test, TestSolrXmlPersistence, TestPseudoReturnFields, DistributedSpellCheckComponentTest, AsyncMigrateRouteKeyTest, PingRequestHandlerTest, DateMathParserTest, TestCursorMarkWithoutUniqueKey, ChangedSchemaMergeTest, TestStressUserVersions, OutputWriterTest, MinimalSchemaTest, RequestHandlersTest, TestPartialUpdateDeduplication, AtomicUpdatesTest, ReturnFieldsTest, TestSolrDeletionPolicy1, TestDFRSimilarityFactory, SolrRequestParserTest, TestValueSourceCache, TestExceedMaxTermLength, ExternalFileFieldSortTest, TestSolrJ, TestShardHandlerFactory, TestLMDirichletSimilarityFactory, AnalysisErrorHandlingTest, FieldAnalysisRequestHandlerTest, TestTolerantSearch, TestCloudInspectUtil, TestIndexSearcher, ClusterStateTest, IndexSchemaTest, CurrencyFieldOpenExchangeTest, TestReversedWildcardFilterFactory, PolyFieldTest, TestReload, SortByFunctionTest, ScriptEngineTest, DocumentBuilderTest, SignatureUpdateProcessorFactoryTest, DocExpirationUpdateProcessorFactoryTest, TestRandomDVFaceting, AddSchemaFieldsUpdateProcessorFactoryTest, TestUpdate, ZkControllerTest, FastVectorHighlighterTest, TestNRTOpen, BadComponentTest, TermsComponentTest, LegacyHTMLStripCharFilterTest, TestInfoStreamLogging, SuggesterWFSTTest, EnumFieldTest, DocValuesTest, TestAtomicUpdateErrorCases, ShardRoutingCustomTest, TestStressLucene, CursorPagingTest, AutoCommitTest, TestElisionMultitermQuery, SimpleFacetsTest, HdfsUnloadDistributedZkTest, DistributedQueryElevationComponentTest, DocValuesMissingTest, ShardRoutingTest, SolrTestCaseJ4Test, URLClassifyProcessorTest, TestManagedResource, RAMDirectoryFactoryTest, SolrCoreTest, TestManagedSchema, TestRequestStatusCollectionAPI, SampleTest, SuggesterTSTTest, TestSolrCoreProperties, TestManagedResourceStorage, TestJmxMonitoredMap, TestSerializedLuceneMatchVersion, OverseerTest, TestMiniSolrCloudCluster, TestConfig, MigrateRouteKeyTest, DocumentAnalysisRequestHandlerTest, SpellingQueryConverterTest, InfoHandlerTest, TestClassNameShortening, TestRecovery, FieldFacetExtrasTest, TestAnalyzedSuggestions, FullSolrCloudDistribCmdsTest, UpdateParamsTest, MultiThreadedOCPTest, TestDocBasedVersionConstraints, TestFunctionQuery, NoCacheHeaderTest, CopyFieldTest, EchoParamsTest, TestXIncludeConfig, CollectionsAPIAsyncDistributedZkTest, TestSchemaResource, TestCSVLoader, CacheHeaderTest, SyncSliceTest, TestComponentsName, TestCustomSort, TestStressRecovery, TestBinaryResponseWriter, TestSearchPerf, SoftAutoCommitTest, TestQuerySenderListener, SpellCheckCollatorTest, DistanceFunctionTest, AssignTest, TestQuerySenderNoQuery, TestQueryUtils, TestPostingsSolrHighlighter, TestCollectionAPI, DeleteShardTest, HdfsSyncSliceTest, TestCharFilters, RequiredFieldsTest, SystemInfoHandlerTest, UpdateRequestProcessorFactoryTest, TestStandardQParsers, QueryFacetTest, TestDefaultSimilarityFactory, TestJmxIntegration, SpatialFilterTest, NumericFieldsTest, TestPhraseSuggestions, ShowFileRequestHandlerTest, TestLRUCache, HighlighterConfigTest, RecoveryZkTest, TestDistribDocBasedVersion, SuggesterFSTTest, TestJoin, TestLMJelinekMercerSimilarityFactory, DisMaxRequestHandlerTest, OverseerStatusTest, TestTrie, HighlighterTest, TestPHPSerializedResponseWriter, CoreAdminHandlerTest, RegexBoostProcessorTest, TestIndexingPerformance, TestExtendedDismaxParser, TestBadConfig, ExpressionTest, AbstractAnalyticsFacetTest, ChaosMonkeySafeLeaderTest, BasicDistributedZk2Test, UnloadDistributedZkTest, OpenCloseCoreStressTest, LeaderElectionIntegrationTest, BasicZkTest, TestReplicationHandler, ClusterStateUpdateTest, ZkSolrClientTest, TestZkChroot, ZkCLITest, TestDistributedSearch, TestDistributedGrouping, TestFaceting, TestHashPartitioner, TermVectorComponentDistributedTest, TestRealTimeGet, TestStressReorder, TestMultiCoreConfBootstrap, TestStressVersions, TestCoreContainer, SolrCmdDistributorTest, PeerSyncTest, BadIndexSchemaTest, ConvertedLegacyTest, TestSort, TestFiltering, BasicFunctionalityTest, TestLazyCores, CurrencyFieldXmlFileTest, TestCoreDiscovery, AnalysisAfterCoreReloadTest, SuggesterTest, WordBreakSolrSpellCheckerTest, SchemaVersionSpecificBehaviorTest, SolrCoreCheckLockOnStartupTest, FieldMutatingUpdateProcessorTest, QueryEqualityTest, DirectUpdateHandlerOptimizeTest, DefaultValueUpdateProcessorTest, StatelessScriptUpdateProcessorFactoryTest, TestRemoteStreaming, DocValuesMultiTest, SolrInfoMBeanTest, XsltUpdateRequestHandlerTest, DebugComponentTest, IndexBasedSpellCheckerTest, TestSurroundQueryParser, LukeRequestHandlerTest, StandardRequestHandlerTest, TestWriterPerf, TestQueryTypes, PrimitiveFieldTypeTest, TestOmitPositions, FileBasedSpellCheckerTest, XmlUpdateRequestHandlerTest, PathHierarchyTokenizerFactoryTest, TermVectorComponentTest, TestSolrQueryParser, TestArbitraryIndexDir, IndexSchemaRuntimeFieldTest, LoggingHandlerTest, SolrPluginUtilsTest, TestCollationField, JSONWriterTest, TestCSVResponseWriter, MBeansHandlerTest, UniqFieldsUpdateProcessorFactoryTest, CSVRequestHandlerTest, CoreContainerCoreInitFailuresTest, TestLFUCache, ResponseLogComponentTest, SolrIndexConfigTest, TestMergePolicyConfig, TestSolrDeletionPolicy2, TestDocSet, TestBinaryField, TestFuzzyAnalyzedSuggestions, DirectSolrConnectionTest, NotRequiredUniqueKeyTest, TestLuceneMatchVersion, SpellPossibilityIteratorTest, TestCodecSupport, SynonymTokenizerTest, TestSweetSpotSimilarityFactory, TestPerFieldSimilarity, TestBM25SimilarityFactory, TestFastWriter, TimeZoneUtilsTest, OpenExchangeRatesOrgProviderTest, PluginInfoTest, TestFastLRUCache, ChaosMonkeyNothingIsSafeTest, TestSolrXMLSerializer, PreAnalyzedFieldTest, TestSystemIdResolver, PrimUtilsTest, DOMUtilTest, TestUtils, TestDocumentBuilder, ZkNodePropsTest, SliceStateTest, UUIDFieldTest, FileUtilsTest, CircularListTest, TestRTGBase, AbstractAnalyticsStatsTest, NoFacetTest, FieldFacetTest, RangeFacetTest, FunctionTest, ConnectionManagerTest, CustomCollectionTest, DeleteInactiveReplicaTest, DeleteReplicaTest, DistribCursorPagingTest, DistribDocExpirationUpdateProcessorTest, HttpPartitionTest]
   [junit4] Completed in 120.37s, 1 test, 1 failure <<< FAILURES!

[...truncated 277 lines...]
BUILD FAILED
/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/build.xml:467: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/build.xml:447: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/build.xml:45: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/extra-targets.xml:37: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build.xml:189: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/common-build.xml:496: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/lucene/common-build.xml:1298: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/lucene/common-build.xml:922: There were test failures: 418 suites, 1710 tests, 1 error, 1 failure, 43 ignored (16 assumptions)

Total time: 115 minutes 40 seconds
Build step 'Invoke Ant' marked build as failure
[description-setter] Description set: Java: 64bit/jdk1.7.0 -XX:+UseCompressedOops -XX:+UseSerialGC
Archiving artifacts
Recording test results
Email was triggered for: Failure - Any
Sending email for trigger: Failure - Any