lucene-dev mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From Policeman Jenkins Server <jenk...@thetaphi.de>
Subject [JENKINS] Lucene-Solr-4.x-Linux (64bit/jdk1.7.0_51) - Build # 9885 - Failure!
Date Fri, 04 Apr 2014 23:50:27 GMT
Build: http://jenkins.thetaphi.de/job/Lucene-Solr-4.x-Linux/9885/
Java: 64bit/jdk1.7.0_51 -XX:-UseCompressedOops -XX:+UseConcMarkSweepGC -XX:-UseSuperWord

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

Error Message:
Unexpected shard leader coll:collection1 shard:shard1 expected:<core[1]> but was:<core[4]>

Stack Trace:
org.junit.ComparisonFailure: Unexpected shard leader coll:collection1 shard:shard1 expected:<core[1]> but was:<core[4]>
	at __randomizedtesting.SeedInfo.seed([79EF914886CFCE36:A7BC16BF9C573BC7]:0)
	at org.junit.Assert.assertEquals(Assert.java:125)
	at org.apache.solr.cloud.OverseerTest.verifyShardLeader(OverseerTest.java:601)
	at org.apache.solr.cloud.OverseerTest.testShardLeaderChange(OverseerTest.java:762)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:606)
	at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1618)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:827)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:863)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:877)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
	at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:50)
	at org.apache.lucene.util.TestRuleFieldCacheSanity$1.evaluate(TestRuleFieldCacheSanity.java:51)
	at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
	at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:49)
	at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:65)
	at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:360)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:793)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:453)
	at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:836)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:738)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:772)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:783)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
	at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
	at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:42)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
	at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
	at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:43)
	at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
	at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:65)
	at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:55)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:360)
	at java.lang.Thread.run(Thread.java:744)




Build Log:
[...truncated 11208 lines...]
   [junit4] Suite: org.apache.solr.cloud.OverseerTest
   [junit4]   2> Creating dataDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./solrtest-OverseerTest-1396654591551
   [junit4]   2> 647364 T3568 oas.SolrTestCaseJ4.buildSSLConfig Randomized ssl (true) and clientAuth (false)
   [junit4]   2> 647364 T3568 oas.SolrTestCaseJ4.initCore ####initCore
   [junit4]   2> 647364 T3568 oas.SolrTestCaseJ4.initCore ####initCore end
   [junit4]   2> 647368 T3568 oas.SolrTestCaseJ4.setUp ###Starting testStateChange
   [junit4]   2> 647368 T3568 oasc.ZkTestServer.run STARTING ZK TEST SERVER
   [junit4]   2> 647369 T3569 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
   [junit4]   2> 647469 T3568 oasc.ZkTestServer.run start zk server on port:51429
   [junit4]   2> 647470 T3568 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 647552 T3575 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@7a285832 name:ZooKeeperConnection Watcher:127.0.0.1:51429/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 647552 T3568 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 647553 T3568 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 647555 T3577 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@fb958d5 name:ZooKeeperConnection Watcher:127.0.0.1:51429 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 647555 T3568 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 647557 T3568 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 647558 T3579 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@faec21b name:ZooKeeperConnection Watcher:127.0.0.1:51429 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 647558 T3568 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 647558 T3568 oascc.SolrZkClient.makePath makePath: /solr
   [junit4]   2> 647560 T3568 oascc.SolrZkClient.makePath makePath: /live_nodes
   [junit4]   2> 647562 T3568 oascc.SolrZkClient.makePath makePath: /clusterstate.json
   [junit4]   2> 647563 T3568 oascc.SolrZkClient.makePath makePath: /aliases.json
   [junit4]   2> 647564 T3568 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 647566 T3568 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 647568 T3581 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@2dbe1bbd name:ZooKeeperConnection Watcher:127.0.0.1:51429/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 647568 T3568 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 647569 T3568 oascc.SolrZkClient.makePath makePath: /overseer_elect
   [junit4]   2> 647570 T3568 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
   [junit4]   2> 647574 T3568 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:51429_solr
   [junit4]   2> 647575 T3568 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
   [junit4]   2> 647576 T3568 oasc.Overseer.start Overseer (id=91531155312345091-127.0.0.1:51429_solr-n_0000000000) starting
   [junit4]   2> 647577 T3568 oascc.SolrZkClient.makePath makePath: /overseer/queue
   [junit4]   2> 647580 T3568 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
   [junit4]   2> 647582 T3568 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-failure
   [junit4]   2> 647584 T3568 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-running
   [junit4]   2> 647590 T3568 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-completed
   [junit4]   2> 647593 T3568 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
   [junit4]   2> 647597 T3583 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
   [junit4]   2> 647598 T3582 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
   [junit4]   2> 647598 T3583 oasc.OverseerCollectionProcessor.prioritizeOverseerNodes prioritizing overseer nodes at 127.0.0.1:51429_solr
   [junit4]   2> 647599 T3568 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 647599 T3582 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 647600 T3582 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=null message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "base_url":"http://127.0.0.1/solr",
   [junit4]   2> 	  "node_name":"node1",
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "core":"core1",
   [junit4]   2> 	  "roles":"",
   [junit4]   2> 	  "state":"recovering"}
   [junit4]   2> 647600 T3582 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
   [junit4]   2> 647604 T3581 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 647604 T3575 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 0)
   [junit4]   2> 647650 T3568 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 647652 T3581 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 647653 T3582 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 647654 T3582 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=null message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "base_url":"http://127.0.0.1/solr",
   [junit4]   2> 	  "node_name":"node1",
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "core":"core1",
   [junit4]   2> 	  "roles":"",
   [junit4]   2> 	  "state":"active"}
   [junit4]   2> 647654 T3582 oasc.Overseer$ClusterStateUpdater.updateState node=core_node1 is already registered
   [junit4]   2> 647654 T3582 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
   [junit4]   2> 647656 T3581 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 647758 T3575 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 0)
   [junit4]   2> 647804 T3568 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:51429 51429
   [junit4]   2> 647974 T3569 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:51429 51429
   [junit4]   2> 647976 T3568 oas.SolrTestCaseJ4.tearDown ###Ending testStateChange
   [junit4]   2> 647976 T3582 oasc.Overseer$ClusterStateUpdater.run Overseer Loop exiting : 127.0.0.1:51429_solr
   [junit4]   2> 647977 T3584 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:302)
   [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:291)
   [junit4]   2> 
   [junit4]   1> client port:0.0.0.0/0.0.0.0:0
   [junit4]   2> 647980 T3568 oas.SolrTestCaseJ4.setUp ###Starting testDoubleAssignment
   [junit4]   2> 647981 T3568 oasc.ZkTestServer.run STARTING ZK TEST SERVER
   [junit4]   2> 647981 T3585 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
   [junit4]   2> 648081 T3568 oasc.ZkTestServer.run start zk server on port:51788
   [junit4]   2> 648082 T3568 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 648084 T3591 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@4a3839da name:ZooKeeperConnection Watcher:127.0.0.1:51788/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 648084 T3568 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 648085 T3568 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 648087 T3593 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@5ed82ee3 name:ZooKeeperConnection Watcher:127.0.0.1:51788 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 648087 T3568 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 648098 T3568 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 648099 T3595 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@4b141ef4 name:ZooKeeperConnection Watcher:127.0.0.1:51788 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 648099 T3568 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 648099 T3568 oascc.SolrZkClient.makePath makePath: /solr
   [junit4]   2> 648104 T3568 oascc.SolrZkClient.makePath makePath: /live_nodes
   [junit4]   2> 648105 T3568 oascc.SolrZkClient.makePath makePath: /clusterstate.json
   [junit4]   2> 648107 T3568 oascc.SolrZkClient.makePath makePath: /aliases.json
   [junit4]   2> 648108 T3568 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 648111 T3568 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 648114 T3597 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1635b0 name:ZooKeeperConnection Watcher:127.0.0.1:51788/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 648114 T3568 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 648115 T3568 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 648117 T3568 oascc.SolrZkClient.makePath makePath: /live_nodes/node1
   [junit4]   2> 648119 T3597 oascc.ZkStateReader$3.process Updating live nodes... (1)
   [junit4]   2> 648119 T3591 oascc.ZkStateReader$3.process Updating live nodes... (1)
   [junit4]   2> 648121 T3568 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 648122 T3599 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@7cee30db name:ZooKeeperConnection Watcher:127.0.0.1:51788/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 648123 T3568 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 648123 T3568 oascc.SolrZkClient.makePath makePath: /overseer_elect
   [junit4]   2> 648125 T3568 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
   [junit4]   2> 648128 T3568 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:51788_solr
   [junit4]   2> 648129 T3568 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
   [junit4]   2> 648130 T3568 oasc.Overseer.start Overseer (id=91531155352584196-127.0.0.1:51788_solr-n_0000000000) starting
   [junit4]   2> 648132 T3568 oascc.SolrZkClient.makePath makePath: /overseer/queue
   [junit4]   2> 648134 T3568 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
   [junit4]   2> 648137 T3568 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-failure
   [junit4]   2> 648139 T3568 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-running
   [junit4]   2> 648144 T3568 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-completed
   [junit4]   2> 648147 T3568 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
   [junit4]   2> 648152 T3601 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
   [junit4]   2> 648153 T3600 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
   [junit4]   2> 648153 T3601 oasc.OverseerCollectionProcessor.prioritizeOverseerNodes prioritizing overseer nodes at 127.0.0.1:51788_solr
   [junit4]   2> 648155 T3600 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 648155 T3600 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"recovering",
   [junit4]   2> 	  "node_name":"node1",
   [junit4]   2> 	  "core":"core1",
   [junit4]   2> 	  "core_node_name":"core_node1",
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "numShards":"1",
   [junit4]   2> 	  "base_url":"http://node1/solr/"}
   [junit4]   2> 648156 T3600 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1]
   [junit4]   2> 648156 T3600 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
   [junit4]   2> 648158 T3599 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 648159 T3591 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> 648162 T3597 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> 648654 T3568 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
   [junit4]   2> 648663 T3568 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 648667 T3599 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 648668 T3568 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 648669 T3600 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 648669 T3591 oascc.ZkStateReader$3.process Updating live nodes... (0)
   [junit4]   2> 648670 T3568 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 648671 T3597 oascc.ZkStateReader$3.process Updating live nodes... (0)
   [junit4]   2> 648672 T3603 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1ac82b72 name:ZooKeeperConnection Watcher:127.0.0.1:51788/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 648672 T3568 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 648672 T3599 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 648673 T3568 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 648675 T3568 oascc.SolrZkClient.makePath makePath: /live_nodes/node1
   [junit4]   2> 648677 T3591 oascc.ZkStateReader$3.process Updating live nodes... (1)
   [junit4]   2> 648677 T3603 oascc.ZkStateReader$3.process Updating live nodes... (1)
   [junit4]   2> 648679 T3599 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 648679 T3568 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
   [junit4]   2> 648679 T3600 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"recovering",
   [junit4]   2> 	  "node_name":"node1",
   [junit4]   2> 	  "core":"core1",
   [junit4]   2> 	  "core_node_name":"core_node1",
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "numShards":"1",
   [junit4]   2> 	  "base_url":"http://node1/solr/"}
   [junit4]   2> 648680 T3600 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
   [junit4]   2> 648681 T3599 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 648683 T3568 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 648687 T3599 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 648690 T3599 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 648792 T3591 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> 648792 T3603 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> 648794 T3568 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 648796 T3591 oascc.ZkStateReader$3.process Updating live nodes... (0)
   [junit4]   2> 648796 T3603 oascc.ZkStateReader$3.process Updating live nodes... (0)
   [junit4]   2> 648798 T3568 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:51788 51788
   [junit4]   2> 648956 T3585 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:51788 51788
   [junit4]   2> 648957 T3568 oas.SolrTestCaseJ4.tearDown ###Ending testDoubleAssignment
   [junit4]   2> 648957 T3600 oasc.Overseer$ClusterStateUpdater.run Overseer Loop exiting : 127.0.0.1:51788_solr
   [junit4]   2> 648958 T3604 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:302)
   [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:291)
   [junit4]   2> 
   [junit4]   1> client port:0.0.0.0/0.0.0.0:0
   [junit4]   2> 648964 T3568 oas.SolrTestCaseJ4.setUp ###Starting testBadQueueItem
   [junit4]   2> 648964 T3568 oasc.ZkTestServer.run STARTING ZK TEST SERVER
   [junit4]   2> 648964 T3605 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
   [junit4]   2> 649064 T3568 oasc.ZkTestServer.run start zk server on port:39845
   [junit4]   2> 649065 T3568 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 649068 T3611 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@7f584ce0 name:ZooKeeperConnection Watcher:127.0.0.1:39845 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 649068 T3568 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 649085 T3568 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 649087 T3613 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@70e382c5 name:ZooKeeperConnection Watcher:127.0.0.1:39845 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 649087 T3568 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 649087 T3568 oascc.SolrZkClient.makePath makePath: /solr
   [junit4]   2> 649089 T3568 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 649092 T3615 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@7630882a name:ZooKeeperConnection Watcher:127.0.0.1:39845/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 649093 T3568 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 649093 T3568 oascc.SolrZkClient.makePath makePath: /live_nodes
   [junit4]   2> 649097 T3568 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 649098 T3617 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@32beab36 name:ZooKeeperConnection Watcher:127.0.0.1:39845/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 649098 T3568 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 649099 T3568 oascc.SolrZkClient.makePath makePath: /overseer_elect
   [junit4]   2> 649101 T3568 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
   [junit4]   2> 649105 T3568 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:39845_solr
   [junit4]   2> 649105 T3568 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
   [junit4]   2> 649107 T3568 oasc.Overseer.start Overseer (id=91531155418185731-127.0.0.1:39845_solr-n_0000000000) starting
   [junit4]   2> 649108 T3568 oascc.SolrZkClient.makePath makePath: /overseer/queue
   [junit4]   2> 649111 T3568 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
   [junit4]   2> 649114 T3568 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-failure
   [junit4]   2> 649116 T3568 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-running
   [junit4]   2> 649119 T3568 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-completed
   [junit4]   2> 649125 T3568 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
   [junit4]   2> 649130 T3619 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
   [junit4]   2> 649130 T3568 oascc.SolrZkClient.makePath makePath: /clusterstate.json
   [junit4]   2> 649130 T3619 oasc.OverseerCollectionProcessor.prioritizeOverseerNodes prioritizing overseer nodes at 127.0.0.1:39845_solr
   [junit4]   2> 649130 T3618 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
   [junit4]   2> 649132 T3568 oascc.SolrZkClient.makePath makePath: /aliases.json
   [junit4]   2> 649133 T3568 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 649135 T3568 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 649136 T3621 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@722aef5e name:ZooKeeperConnection Watcher:127.0.0.1:39845/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 649137 T3568 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 649137 T3568 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 649139 T3568 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1
   [junit4]   2> 649141 T3615 oascc.ZkStateReader$3.process Updating live nodes... (1)
   [junit4]   2> 649142 T3621 oascc.ZkStateReader$3.process Updating live nodes... (1)
   [junit4]   2> 649143 T3617 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 649144 T3618 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 649145 T3618 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"active",
   [junit4]   2> 	  "node_name":"127.0.0.1",
   [junit4]   2> 	  "core":"core1",
   [junit4]   2> 	  "core_node_name":"node1",
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "numShards":"3",
   [junit4]   2> 	  "base_url":"http://127.0.0.1/solr/"}
   [junit4]   2> 649145 T3618 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1, shard2, shard3]
   [junit4]   2> 649145 T3618 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard3
   [junit4]   2> 649147 T3617 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 649147 T3615 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> 649147 T3621 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> 649643 T3568 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard3/election
   [junit4]   2> 649652 T3568 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard3
   [junit4]   2> 649656 T3617 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 649657 T3618 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 649658 T3617 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 649660 T3618 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"active",
   [junit4]   2> 	  "node_name":"127.0.0.1",
   [junit4]   2> 	  "core":"core2",
   [junit4]   2> 	  "core_node_name":"node2",
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "numShards":"3",
   [junit4]   2> 	  "base_url":"http://127.0.0.1/solr/"}
   [junit4]   2> 649660 T3618 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
   [junit4]   2> 649660 T3618 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
   [junit4]   2> 649662 T3617 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 649765 T3615 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> 649765 T3621 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> 650158 T3568 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
   [junit4]   2> 650165 T3568 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 650170 T3617 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 650170 T3617 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 650170 T3617 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 650171 T3617 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 650171 T3618 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 650174 T3618 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"active",
   [junit4]   2> 	  "node_name":"127.0.0.1",
   [junit4]   2> 	  "core":"core3",
   [junit4]   2> 	  "core_node_name":"node3",
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "numShards":"3",
   [junit4]   2> 	  "base_url":"http://127.0.0.1/solr/"}
   [junit4]   2> 650174 T3618 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
   [junit4]   2> 650174 T3618 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard2
   [junit4]   2> 650176 T3617 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 650278 T3615 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> 650278 T3621 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> 650671 T3568 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard2/election
   [junit4]   2> 650684 T3568 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard2
   [junit4]   2> 650691 T3617 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 650691 T3617 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 650692 T3617 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 650694 T3618 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 650698 T3617 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 650801 T3621 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> 650801 T3615 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> 650845 T3617 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 650845 T3617 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 650846 T3617 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 650849 T3618 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 650850 T3617 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 650851 T3618 oasc.Overseer$ClusterStateUpdater.checkKeyExistence ERROR Skipping invalid Overseer message because it has no collection specified: {
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"active",
   [junit4]   2> 	  "node_name":"127.0.0.1",
   [junit4]   2> 	  "core":"core0",
   [junit4]   2> 	  "core_node_name":"node0",
   [junit4]   2> 	  "collection":"",
   [junit4]   2> 	  "numShards":"1",
   [junit4]   2> 	  "base_url":"http://127.0.0.1/solr/"}
   [junit4]   2> 650857 T3618 oasc.Overseer$ClusterStateUpdater.checkKeyExistence ERROR Skipping invalid Overseer message because it has no collection specified: {
   [junit4]   2> 	  "operation":"deletecore",
   [junit4]   2> 	  "node_name":"127.0.0.1",
   [junit4]   2> 	  "core":"core0",
   [junit4]   2> 	  "core_node_name":"node0",
   [junit4]   2> 	  "collection":""}
   [junit4]   2> 650862 T3617 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 650864 T3618 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"active",
   [junit4]   2> 	  "node_name":"127.0.0.1",
   [junit4]   2> 	  "core":"core1",
   [junit4]   2> 	  "core_node_name":"node1",
   [junit4]   2> 	  "collection":"collection2",
   [junit4]   2> 	  "numShards":"3",
   [junit4]   2> 	  "base_url":"http://127.0.0.1/solr/"}
   [junit4]   2> 650864 T3618 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection2 with shards [shard1, shard2, shard3]
   [junit4]   2> 650865 T3618 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard3
   [junit4]   2> 650869 T3617 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 650971 T3615 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> 650971 T3621 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> 651354 T3568 oascc.SolrZkClient.makePath makePath: /collections/collection2/leader_elect/shard3/election
   [junit4]   2> 651363 T3568 oascc.SolrZkClient.makePath makePath: /collections/collection2/leaders/shard3
   [junit4]   2> 651366 T3617 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 651367 T3617 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 651367 T3617 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 651368 T3617 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 651368 T3618 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 651371 T3618 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"active",
   [junit4]   2> 	  "node_name":"127.0.0.1",
   [junit4]   2> 	  "core":"core2",
   [junit4]   2> 	  "core_node_name":"node2",
   [junit4]   2> 	  "collection":"collection2",
   [junit4]   2> 	  "numShards":"3",
   [junit4]   2> 	  "base_url":"http://127.0.0.1/solr/"}
   [junit4]   2> 651371 T3618 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
   [junit4]   2> 651371 T3618 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
   [junit4]   2> 651373 T3617 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 651475 T3615 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> 651475 T3621 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> 651868 T3568 oascc.SolrZkClient.makePath makePath: /collections/collection2/leader_elect/shard1/election
   [junit4]   2> 651874 T3568 oascc.SolrZkClient.makePath makePath: /collections/collection2/leaders/shard1
   [junit4]   2> 651877 T3617 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 651877 T3617 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 651877 T3617 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 651878 T3617 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 651878 T3618 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 651882 T3618 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"active",
   [junit4]   2> 	  "node_name":"127.0.0.1",
   [junit4]   2> 	  "core":"core3",
   [junit4]   2> 	  "core_node_name":"node3",
   [junit4]   2> 	  "collection":"collection2",
   [junit4]   2> 	  "numShards":"3",
   [junit4]   2> 	  "base_url":"http://127.0.0.1/solr/"}
   [junit4]   2> 651883 T3618 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
   [junit4]   2> 651883 T3618 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard2
   [junit4]   2> 651884 T3617 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 651987 T3621 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> 651987 T3615 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> 652378 T3568 oascc.SolrZkClient.makePath makePath: /collections/collection2/leader_elect/shard2/election
   [junit4]   2> 652384 T3568 oascc.SolrZkClient.makePath makePath: /collections/collection2/leaders/shard2
   [junit4]   2> 652388 T3617 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 652388 T3617 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 652388 T3617 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 652389 T3618 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 652391 T3617 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 652493 T3615 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> 652493 T3621 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> 652539 T3606 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x1452f19d4950002, likely client has closed socket
   [junit4]   2> 	at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:228)
   [junit4]   2> 	at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208)
   [junit4]   2> 	at java.lang.Thread.run(Thread.java:744)
   [junit4]   2> 
   [junit4]   2> 652540 T3621 oascc.ZkStateReader$3.process Updating live nodes... (0)
   [junit4]   2> 652542 T3568 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:39845 39845
   [junit4]   2> 652718 T3605 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:39845 39845
   [junit4]   2> 652719 T3568 oas.SolrTestCaseJ4.tearDown ###Ending testBadQueueItem
   [junit4]   2> 652720 T3618 oasc.Overseer$ClusterStateUpdater.run Overseer Loop exiting : 127.0.0.1:39845_solr
   [junit4]   2> 652721 T3622 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:302)
   [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:291)
   [junit4]   2> 
   [junit4]   1> client port:0.0.0.0/0.0.0.0:0
   [junit4]   2> 652725 T3568 oas.SolrTestCaseJ4.setUp ###Starting testShardAssignment
   [junit4]   2> 652725 T3568 oasc.ZkTestServer.run STARTING ZK TEST SERVER
   [junit4]   2> 652726 T3623 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
   [junit4]   2> 652826 T3568 oasc.ZkTestServer.run start zk server on port:52484
   [junit4]   2> 652827 T3568 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 652830 T3629 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@25701a5e name:ZooKeeperConnection Watcher:127.0.0.1:52484 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 652830 T3568 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 652875 T3568 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 652876 T3631 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@7a6b161d name:ZooKeeperConnection Watcher:127.0.0.1:52484 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 652876 T3568 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 652876 T3568 oascc.SolrZkClient.makePath makePath: /solr
   [junit4]   2> 652879 T3568 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 652880 T3633 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1312f5c6 name:ZooKeeperConnection Watcher:127.0.0.1:52484/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 652880 T3568 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 652880 T3568 oascc.SolrZkClient.makePath makePath: /live_nodes
   [junit4]   2> 652882 T3568 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 652883 T3635 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@284aefe name:ZooKeeperConnection Watcher:127.0.0.1:52484/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 652884 T3568 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 652884 T3568 oascc.SolrZkClient.makePath makePath: /overseer_elect
   [junit4]   2> 652886 T3568 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
   [junit4]   2> 652888 T3568 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:52484_solr
   [junit4]   2> 652889 T3568 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
   [junit4]   2> 652890 T3568 oasc.Overseer.start Overseer (id=91531155664142339-127.0.0.1:52484_solr-n_0000000000) starting
   [junit4]   2> 652894 T3568 oascc.SolrZkClient.makePath makePath: /overseer/queue
   [junit4]   2> 652897 T3568 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
   [junit4]   2> 652899 T3568 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-failure
   [junit4]   2> 652902 T3568 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-running
   [junit4]   2> 652904 T3568 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-completed
   [junit4]   2> 652910 T3568 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
   [junit4]   2> 652915 T3637 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
   [junit4]   2> 652915 T3568 oascc.SolrZkClient.makePath makePath: /clusterstate.json
   [junit4]   2> 652916 T3637 oasc.OverseerCollectionProcessor.prioritizeOverseerNodes prioritizing overseer nodes at 127.0.0.1:52484_solr
   [junit4]   2> 652916 T3636 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
   [junit4]   2> 652920 T3568 oascc.SolrZkClient.makePath makePath: /aliases.json
   [junit4]   2> 652922 T3568 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 652923 T3568 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 652925 T3639 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@f252adb name:ZooKeeperConnection Watcher:127.0.0.1:52484/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 652925 T3568 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 652926 T3568 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 652928 T3568 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1
   [junit4]   2> 652930 T3639 oascc.ZkStateReader$3.process Updating live nodes... (1)
   [junit4]   2> 652930 T3633 oascc.ZkStateReader$3.process Updating live nodes... (1)
   [junit4]   2> 652934 T3635 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 652935 T3636 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 652935 T3636 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"active",
   [junit4]   2> 	  "node_name":"127.0.0.1",
   [junit4]   2> 	  "core":"core1",
   [junit4]   2> 	  "core_node_name":"node1",
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "numShards":"3",
   [junit4]   2> 	  "base_url":"http://127.0.0.1/solr/"}
   [junit4]   2> 652936 T3636 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1, shard2, shard3]
   [junit4]   2> 652936 T3636 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard3
   [junit4]   2> 652938 T3635 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 652940 T3633 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> 652940 T3639 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> 653434 T3568 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard3/election
   [junit4]   2> 653451 T3568 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard3
   [junit4]   2> 653456 T3635 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 653457 T3636 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 653458 T3635 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 653464 T3636 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"active",
   [junit4]   2> 	  "node_name":"127.0.0.1",
   [junit4]   2> 	  "core":"core2",
   [junit4]   2> 	  "core_node_name":"node2",
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "numShards":"3",
   [junit4]   2> 	  "base_url":"http://127.0.0.1/solr/"}
   [junit4]   2> 653464 T3636 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
   [junit4]   2> 653464 T3636 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
   [junit4]   2> 653467 T3635 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 653571 T3633 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> 653571 T3639 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> 653958 T3568 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
   [junit4]   2> 653964 T3568 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 653967 T3635 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 653967 T3635 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 653968 T3635 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 653969 T3635 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 653969 T3636 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 653972 T3636 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"active",
   [junit4]   2> 	  "node_name":"127.0.0.1",
   [junit4]   2> 	  "core":"core3",
   [junit4]   2> 	  "core_node_name":"node3",
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "numShards":"3",
   [junit4]   2> 	  "base_url":"http://127.0.0.1/solr/"}
   [junit4]   2> 653972 T3636 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
   [junit4]   2> 653972 T3636 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard2
   [junit4]   2> 653973 T3635 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 654075 T3633 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> 654075 T3639 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> 654469 T3568 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard2/election
   [junit4]   2> 654476 T3568 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard2
   [junit4]   2> 654479 T3635 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 654480 T3635 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 654480 T3635 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 654481 T3635 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 654481 T3636 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 654484 T3636 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"active",
   [junit4]   2> 	  "node_name":"127.0.0.1",
   [junit4]   2> 	  "core":"core4",
   [junit4]   2> 	  "core_node_name":"node4",
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "numShards":"3",
   [junit4]   2> 	  "base_url":"http://127.0.0.1/solr/"}
   [junit4]   2> 654484 T3636 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
   [junit4]   2> 654484 T3636 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard3
   [junit4]   2> 654487 T3635 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 654588 T3633 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> 654588 T3639 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> 654981 T3568 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard3/election
   [junit4]   2> 654987 T3635 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 654988 T3635 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 654988 T3635 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 654988 T3636 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 654989 T3636 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"active",
   [junit4]   2> 	  "node_name":"127.0.0.1",
   [junit4]   2> 	  "core":"core5",
   [junit4]   2> 	  "core_node_name":"node5",
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "numShards":"3",
   [junit4]   2> 	  "base_url":"http://127.0.0.1/solr/"}
   [junit4]   2> 654989 T3636 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
   [junit4]   2> 654989 T3636 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
   [junit4]   2> 654995 T3635 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 655097 T3639 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> 655097 T3633 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> 655487 T3568 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
   [junit4]   2> 655493 T3635 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 655493 T3635 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 655494 T3635 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 655495 T3636 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 655495 T3636 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"active",
   [junit4]   2> 	  "node_name":"127.0.0.1",
   [junit4]   2> 	  "core":"core6",
   [junit4]   2> 	  "core_node_name":"node6",
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "numShards":"3",
   [junit4]   2> 	  "base_url":"http://127.0.0.1/solr/"}
   [junit4]   2> 655495 T3636 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
   [junit4]   2> 655496 T3636 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard2
   [junit4]   2> 655498 T3635 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 655599 T3639 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> 655599 T3633 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> 655993 T3568 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard2/election
   [junit4]   2> 656000 T3639 oascc.ZkStateReader$3.process Updating live nodes... (0)
   [junit4]   2> 656002 T3568 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:52484 52484
   [junit4]   2> 656319 T3623 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:52484 52484
   [junit4]   2> 656320 T3568 oas.SolrTestCaseJ4.tearDown ###Ending testShardAssignment
   [junit4]   2> 656321 T3636 oasc.Overseer$ClusterStateUpdater.run Overseer Loop exiting : 127.0.0.1:52484_solr
   [junit4]   2> 656322 T3640 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:302)
   [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:291)
   [junit4]   2> 
   [junit4]   1> client port:0.0.0.0/0.0.0.0:0
   [junit4]   2> 656328 T3568 oas.SolrTestCaseJ4.setUp ###Starting testPlaceholders
   [junit4]   2> 656328 T3568 oasc.ZkTestServer.run STARTING ZK TEST SERVER
   [junit4]   2> 656329 T3641 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
   [junit4]   2> 656430 T3568 oasc.ZkTestServer.run start zk server on port:52723
   [junit4]   2> 656432 T3568 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 656435 T3647 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@47c157c name:ZooKeeperConnection Watcher:127.0.0.1:52723/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 656436 T3568 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 656436 T3568 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 656438 T3649 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@35498167 name:ZooKeeperConnection Watcher:127.0.0.1:52723 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 656438 T3568 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 656455 T3568 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 656456 T3651 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@32c388da name:ZooKeeperConnection Watcher:127.0.0.1:52723 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 656456 T3568 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 656456 T3568 oascc.SolrZkClient.makePath makePath: /solr
   [junit4]   2> 656458 T3568 oascc.SolrZkClient.makePath makePath: /live_nodes
   [junit4]   2> 656459 T3568 oascc.SolrZkClient.makePath makePath: /clusterstate.json
   [junit4]   2> 656460 T3568 oascc.SolrZkClient.makePath makePath: /aliases.json
   [junit4]   2> 656462 T3568 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 656464 T3568 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 656467 T3653 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@4d8e81f3 name:ZooKeeperConnection Watcher:127.0.0.1:52723/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 656467 T3568 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 656468 T3568 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 656470 T3568 oascc.SolrZkClient.makePath makePath: /live_nodes/node1
   [junit4]   2> 656472 T3653 oascc.ZkStateReader$3.process Updating live nodes... (1)
   [junit4]   2> 656472 T3647 oascc.ZkStateReader$3.process Updating live nodes... (1)
   [junit4]   2> 656472 T3568 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 656473 T3655 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@66c2db4c name:ZooKeeperConnection Watcher:127.0.0.1:52723/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 656474 T3568 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 656474 T3568 oascc.SolrZkClient.makePath makePath: /overseer_elect
   [junit4]   2> 656476 T3568 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
   [junit4]   2> 656478 T3568 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:52723_solr
   [junit4]   2> 656479 T3568 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
   [junit4]   2> 656480 T3568 oasc.Overseer.start Overseer (id=91531155900399620-127.0.0.1:52723_solr-n_0000000000) starting
   [junit4]   2> 656481 T3568 oascc.SolrZkClient.makePath makePath: /overseer/queue
   [junit4]   2> 656483 T3568 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
   [junit4]   2> 656485 T3568 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-failure
   [junit4]   2> 656488 T3568 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-running
   [junit4]   2> 656490 T3568 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-completed
   [junit4]   2> 656494 T3568 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
   [junit4]   2> 656498 T3657 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
   [junit4]   2> 656499 T3657 oasc.OverseerCollectionProcessor.prioritizeOverseerNodes prioritizing overseer nodes at 127.0.0.1:52723_solr
   [junit4]   2> 656499 T3656 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
   [junit4]   2> 656501 T3656 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 656501 T3656 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=12 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"recovering",
   [junit4]   2> 	  "node_name":"node1",
   [junit4]   2> 	  "core":"core1",
   [junit4]   2> 	  "core_node_name":"node1",
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "numShards":"12",
   [junit4]   2> 	  "base_url":"http://node1/solr/"}
   [junit4]   2> 656501 T3656 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1, shard2, shard3, shard4, shard5, shard6, shard7, shard8, shard9, shard10, shard11, shard12]
   [junit4]   2> 656501 T3656 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard8
   [junit4]   2> 656503 T3655 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 656504 T3653 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> 656504 T3647 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> 657000 T3568 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard8/election
   [junit4]   2> 657007 T3568 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard8
   [junit4]   2> 657018 T3655 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 657030 T3568 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 657031 T3656 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 657032 T3647 oascc.ZkStateReader$3.process Updating live nodes... (0)
   [junit4]   2> 657032 T3653 oascc.ZkStateReader$3.process Updating live nodes... (0)
   [junit4]   2> 657033 T3568 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:52723 52723
   [junit4]   2> 657153 T3641 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:52723 52723
   [junit4]   2> 657154 T3568 oas.SolrTestCaseJ4.tearDown ###Ending testPlaceholders
   [junit4]   2> 657154 T3656 oasc.Overseer$ClusterStateUpdater.run Overseer Loop exiting : 127.0.0.1:52723_solr
   [junit4]   2> 657155 T3658 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:302)
   [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:291)
   [junit4]   2> 
   [junit4]   1> client port:0.0.0.0/0.0.0.0:0
   [junit4]   2> 657159 T3568 oas.SolrTestCaseJ4.setUp ###Starting testReplay
   [junit4]   2> 657159 T3568 oasc.ZkTestServer.run STARTING ZK TEST SERVER
   [junit4]   2> 657160 T3659 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
   [junit4]   2> 657260 T3568 oasc.ZkTestServer.run start zk server on port:42495
   [junit4]   2> 657261 T3568 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 657322 T3665 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@7dbacf76 name:ZooKeeperConnection Watcher:127.0.0.1:42495/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 657322 T3568 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 657323 T3568 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 657326 T3667 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@738b06f1 name:ZooKeeperConnection Watcher:127.0.0.1:42495 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 657326 T3568 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 657344 T3568 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 657346 T3669 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@cb0d564 name:ZooKeeperConnection Watcher:127.0.0.1:42495 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 657346 T3568 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 657346 T3568 oascc.SolrZkClient.makePath makePath: /solr
   [junit4]   2> 657348 T3568 oascc.SolrZkClient.makePath makePath: /live_nodes
   [junit4]   2> 657349 T3568 oascc.SolrZkClient.makePath makePath: /clusterstate.json
   [junit4]   2> 657351 T3568 oascc.SolrZkClient.makePath makePath: /aliases.json
   [junit4]   2> 657352 T3568 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 657354 T3568 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
   [junit4]   2> 657356 T3568 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 657358 T3671 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@53c1c985 name:ZooKeeperConnection Watcher:127.0.0.1:42495/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 657358 T3568 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 657358 T3568 oascc.SolrZkClient.makePath makePath: /overseer_elect
   [junit4]   2> 657360 T3568 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
   [junit4]   2> 657362 T3568 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:42495_solr
   [junit4]   2> 657362 T3568 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
   [junit4]   2> 657364 T3568 oasc.Overseer.start Overseer (id=91531155954991107-127.0.0.1:42495_solr-n_0000000000) starting
   [junit4]   2> 657365 T3568 oascc.SolrZkClient.makePath makePath: /overseer/queue
   [junit4]   2> 657367 T3568 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-failure
   [junit4]   2> 657370 T3568 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-running
   [junit4]   2> 657374 T3568 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-completed
   [junit4]   2> 657377 T3568 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
   [junit4]   2> 657381 T3673 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
   [junit4]   2> 657382 T3673 oasc.OverseerCollectionProcessor.prioritizeOverseerNodes prioritizing overseer nodes at 127.0.0.1:42495_solr
   [junit4]   2> 657383 T3672 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 657383 T3672 oasc.Overseer$ClusterStateUpdater.run Replaying operations from work queue.
   [junit4]   2> 657383 T3672 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=null message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "base_url":"http://127.0.0.1/solr",
   [junit4]   2> 	  "node_name":"node1",
   [junit4]   2> 	  "shard":"s1",
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "core":"core1",
   [junit4]   2> 	  "roles":"",
   [junit4]   2> 	  "state":"recovering"}
   [junit4]   2> 657384 T3665 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 0)
   [junit4]   2> 657386 T3672 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=null message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "base_url":"http://127.0.0.1/solr",
   [junit4]   2> 	  "node_name":"node1",
   [junit4]   2> 	  "shard":"s1",
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "core":"core2",
   [junit4]   2> 	  "roles":"",
   [junit4]   2> 	  "state":"recovering"}
   [junit4]   2> 657387 T3665 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 0)
   [junit4]   2> 657388 T3672 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
   [junit4]   2> 657389 T3672 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 657389 T3672 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=null message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "base_url":"http://127.0.0.1/solr",
   [junit4]   2> 	  "node_name":"node1",
   [junit4]   2> 	  "shard":"s1",
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "core":"core3",
   [junit4]   2> 	  "roles":"",
   [junit4]   2> 	  "state":"recovering"}
   [junit4]   2> 657391 T3671 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 657391 T3665 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 0)
   [junit4]   2> 657485 T3568 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:42495 42495
   [junit4]   2> 657500 T3639 oasc.LeaderElector$ElectionWatcher.process WARN  org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /collections/collection1/leader_elect/shard2/election
   [junit4]   2> 	at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
   [junit4]   2> 	at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
   [junit4]   2> 	at org.apache.zookeeper.ZooKeeper.getChildren(ZooKeeper.java:1472)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:260)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:257)
   [junit4]   2> 	at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient.getChildren(SolrZkClient.java:257)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:94)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector.access$200(LeaderElector.java:55)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector$ElectionWatcher.process(LeaderElector.java:303)
   [junit4]   2> 	at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:522)
   [junit4]   2> 	at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:498)
   [junit4]   2> 
   [junit4]   2> 657742 T3659 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:42495 42495
   [junit4]   2> 657742 T3639 oasc.LeaderElector$ElectionWatcher.process WARN  org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /collections/collection1/leader_elect/shard1/election
   [junit4]   2> 	at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
   [junit4]   2> 	at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
   [junit4]   2> 	at org.apache.zookeeper.ZooKeeper.getChildren(ZooKeeper.java:1472)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:260)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:257)
   [junit4]   2> 	at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient.getChildren(SolrZkClient.java:257)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:94)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector.access$200(LeaderElector.java:55)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector$ElectionWatcher.process(LeaderElector.java:303)
   [junit4]   2> 	at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:522)
   [junit4]   2> 	at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:498)
   [junit4]   2> 
   [junit4]   2> 657743 T3568 oas.SolrTestCaseJ4.tearDown ###Ending testReplay
   [junit4]   2> 657743 T3639 oasc.LeaderElector$ElectionWatcher.process WARN  org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /collections/collection1/leader_elect/shard3/election
   [junit4]   2> 	at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
   [junit4]   2> 	at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
   [junit4]   2> 	at org.apache.zookeeper.ZooKeeper.getChildren(ZooKeeper.java:1472)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:260)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:257)
   [junit4]   2> 	at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient.getChildren(SolrZkClient.java:257)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:94)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector.access$200(LeaderElector.java:55)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector$ElectionWatcher.process(LeaderElector.java:303)
   [junit4]   2> 	at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:522)
   [junit4]   2> 	at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:498)
   [junit4]   2> 
   [junit4]   2> 657743 T3672 oasc.Overseer$ClusterStateUpdater.run Overseer Loop exiting : 127.0.0.1:42495_solr
   [junit4]   1> client port:0.0.0.0/0.0.0.0:0
   [junit4]   2> 657745 T3674 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:302)
   [junit4]   2> 	at org.apache.solr.cloud.Overseer$ClusterStateUpdater.access$300(Overseer.java:85)
   [junit4]   2> 	at org.apache.solr.cloud.Overse

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

 oascc.ZkStateReader$3.process Updating live nodes... (7)
   [junit4]   2> 719132 T3953 oascc.ZkStateReader$3.process Updating live nodes... (7)
   [junit4]   2> 719132 T3957 oascc.ZkStateReader$3.process Updating live nodes... (7)
   [junit4]   2> 719132 T3945 oascc.ZkStateReader$3.process Updating live nodes... (7)
   [junit4]   2> 719132 T3955 oascc.ZkStateReader$3.process Updating live nodes... (7)
   [junit4]   2> 719132 T3949 oascc.ZkStateReader$3.process Updating live nodes... (7)
   [junit4]   2> 719132 T3959 oascc.ZkStateReader$3.process Updating live nodes... (7)
   [junit4]   2> 719135 T3959 oascc.ZkStateReader$3.process Updating live nodes... (6)
   [junit4]   2> 719135 T3955 oascc.ZkStateReader$3.process Updating live nodes... (6)
   [junit4]   2> 719135 T3951 oascc.ZkStateReader$3.process Updating live nodes... (6)
   [junit4]   2> 719136 T3953 oascc.ZkStateReader$3.process Updating live nodes... (6)
   [junit4]   2> 719135 T3947 oascc.ZkStateReader$3.process Updating live nodes... (6)
   [junit4]   2> 719135 T3949 oascc.ZkStateReader$3.process Updating live nodes... (6)
   [junit4]   2> 719135 T3957 oascc.ZkStateReader$3.process Updating live nodes... (6)
   [junit4]   2> 719136 T3953 oascc.ZkStateReader$3.process Updating live nodes... (5)
   [junit4]   2> 719136 T3955 oascc.ZkStateReader$3.process Updating live nodes... (5)
   [junit4]   2> 719137 T3951 oascc.ZkStateReader$3.process Updating live nodes... (5)
   [junit4]   2> 719137 T3949 oascc.ZkStateReader$3.process Updating live nodes... (5)
   [junit4]   2> 719137 T3957 oascc.ZkStateReader$3.process Updating live nodes... (5)
   [junit4]   2> 719137 T3959 oascc.ZkStateReader$3.process Updating live nodes... (5)
   [junit4]   2> 719138 T3955 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 719138 T3959 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 719138 T3953 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 719138 T3951 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 719139 T3957 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 719140 T3953 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 719140 T3957 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 719140 T3955 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 719140 T3959 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 719141 T3957 oascc.ZkStateReader$3.process Updating live nodes... (2)
   [junit4]   2> 719141 T3955 oascc.ZkStateReader$3.process Updating live nodes... (2)
   [junit4]   2> 719141 T3959 oascc.ZkStateReader$3.process Updating live nodes... (2)
   [junit4]   2> 719142 T3959 oascc.ZkStateReader$3.process Updating live nodes... (1)
   [junit4]   2> 719142 T3957 oascc.ZkStateReader$3.process Updating live nodes... (1)
   [junit4]   2> 719143 T3959 oascc.ZkStateReader$3.process Updating live nodes... (0)
   [junit4]   2> 719143 T3568 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:57903 57903
   [junit4]   2> 719206 T3813 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:57903 57903
   [junit4]   2> 719208 T3568 oas.SolrTestCaseJ4.tearDown ###Ending testShardAssignmentBigger
   [junit4]   2> 719208 T3826 oasc.Overseer$ClusterStateUpdater.run Overseer Loop exiting : 127.0.0.1:57903_solr
   [junit4]   2> 719209 T4026 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:302)
   [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:291)
   [junit4]   2> 
   [junit4]   1> client port:0.0.0.0/0.0.0.0:0
   [junit4]   2> 719209 T3568 oas.SolrTestCaseJ4.initCore ####initCore
   [junit4]   2> 719210 T3568 oas.SolrTestCaseJ4.initCore ####initCore end
   [junit4]   2> 720358 T3847 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
   [junit4]   2> 720399 T3851 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
   [junit4]   2> 720408 T3853 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
   [junit4]   2> 720496 T3875 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
   [junit4]   2> 720551 T3899 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
   [junit4]   2> 720557 T3901 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
   [junit4]   2> 720561 T3903 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
   [junit4]   2> 720591 T3917 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
   [junit4]   2> 720622 T3937 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
   [junit4]   2> 722210 T3568 oas.SolrTestCaseJ4.deleteCore ###deleteCore
   [junit4]   2> NOTE: test params are: codec=Lucene42, sim=RandomSimilarityProvider(queryNorm=true,coord=no): {}, locale=sq_AL, timezone=Australia/Yancowinna
   [junit4]   2> NOTE: Linux 3.8.0-38-generic amd64/Oracle Corporation 1.7.0_51 (64-bit)/cpus=8,threads=1,free=102771168,total=256028672
   [junit4]   2> NOTE: All tests run in this JVM: [DeleteShardTest, TestShardHandlerFactory, MoreLikeThisHandlerTest, HdfsSyncSliceTest, SimpleFacetsTest, TestLMDirichletSimilarityFactory, SolrIndexSplitterTest, URLClassifyProcessorTest, TestCopyFieldCollectionResource, TestCursorMarkWithoutUniqueKey, TestPHPSerializedResponseWriter, TestReloadAndDeleteDocs, SynonymTokenizerTest, TestConfig, HdfsRecoveryZkTest, TestFreeTextSuggestions, TestSolrXmlPersistence, AutoCommitTest, TestWriterPerf, UUIDFieldTest, TestPerFieldSimilarity, TestRandomMergePolicy, SyncSliceTest, PeerSyncTest, UpdateRequestProcessorFactoryTest, LoggingHandlerTest, TestCoreContainer, ParsingFieldUpdateProcessorsTest, SolrInfoMBeanTest, TestDynamicFieldResource, TestValueSourceCache, TestDistributedMissingSort, CSVRequestHandlerTest, TestBM25SimilarityFactory, CursorMarkTest, TestConfigSets, TestRealTimeGet, TestCharFilters, SOLR749Test, TestLuceneMatchVersion, DocValuesTest, TestFaceting, DirectUpdateHandlerOptimizeTest, TestRecoveryHdfs, BinaryUpdateRequestHandlerTest, WordBreakSolrSpellCheckerTest, FileBasedSpellCheckerTest, TestSolrDeletionPolicy1, TestPseudoReturnFields, TestRemoteStreaming, BasicFunctionalityTest, QueryResultKeyTest, TestSearchPerf, AnalysisErrorHandlingTest, TestSort, DistributedTermsComponentTest, TestStressUserVersions, DateMathParserTest, TermsComponentTest, TestSuggestSpellingConverter, SpatialFilterTest, TestElisionMultitermQuery, TriLevelCompositeIdRoutingTest, ClusterStateTest, DocExpirationUpdateProcessorFactoryTest, TestMergePolicyConfig, TestNonDefinedSimilarityFactory, CacheHeaderTest, ChangedSchemaMergeTest, TestReversedWildcardFilterFactory, AnalysisAfterCoreReloadTest, FastVectorHighlighterTest, ShowFileRequestHandlerTest, TestManagedSchema, TestSearcherReuse, SampleTest, TestClassNameShortening, TestCollapseQParserPlugin, SpellPossibilityIteratorTest, LeaderElectionTest, TestInfoStreamLogging, HdfsDirectoryTest, UnloadDistributedZkTest, TestSurroundQueryParser, ScriptEngineTest, TestReplicationHandler, TestHighFrequencyDictionaryFactory, TestLFUCache, MBeansHandlerTest, ZkCLITest, BadComponentTest, CoreMergeIndexesAdminHandlerTest, BasicDistributedZkTest, ChaosMonkeySafeLeaderTest, OpenCloseCoreStressTest, OverseerTest]
   [junit4] Completed on J0 in 74.87s, 9 tests, 1 failure <<< FAILURES!

[...truncated 581 lines...]
BUILD FAILED
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/build.xml:467: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/build.xml:447: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/build.xml:45: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/extra-targets.xml:37: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build.xml:189: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/common-build.xml:496: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/lucene/common-build.xml:1276: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/lucene/common-build.xml:908: There were test failures: 382 suites, 1611 tests, 1 failure, 37 ignored (16 assumptions)

Total time: 57 minutes 8 seconds
Build step 'Invoke Ant' marked build as failure
Description set: Java: 64bit/jdk1.7.0_51 -XX:-UseCompressedOops -XX:+UseConcMarkSweepGC -XX:-UseSuperWord
Archiving artifacts
Recording test results
Email was triggered for: Failure
Sending email for trigger: Failure



Mime
View raw message