lucene-dev mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From Policeman Jenkins Server <jenk...@thetaphi.de>
Subject [JENKINS] Lucene-Solr-4.x-Linux (32bit/jdk1.7.0_60-ea-b14) - Build # 10080 - Failure!
Date Tue, 29 Apr 2014 18:13:11 GMT
Build: http://jenkins.thetaphi.de/job/Lucene-Solr-4.x-Linux/10080/
Java: 32bit/jdk1.7.0_60-ea-b14 -client -XX:+UseSerialGC

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

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

Stack Trace:
org.apache.solr.common.SolrException: Could not register as the leader because creating the ephemeral registration node in ZooKeeper failed
	at __randomizedtesting.SeedInfo.seed([1106F9229655B368:150E76D184F05C49]:0)
	at org.apache.solr.cloud.ShardLeaderElectionContextBase.runLeaderProcess(ElectionContext.java:136)
	at org.apache.solr.cloud.LeaderElector.runIamLeaderProcess(LeaderElector.java:142)
	at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:110)
	at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:134)
	at org.apache.solr.cloud.LeaderElector.joinElection(LeaderElector.java:267)
	at org.apache.solr.cloud.OverseerTest$MockZKController.publishState(OverseerTest.java:155)
	at org.apache.solr.cloud.OverseerTest.testOverseerFailure(OverseerTest.java:661)
	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 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)
Caused by: org.apache.solr.common.SolrException: org.apache.zookeeper.KeeperException$NodeExistsException: KeeperErrorCode = NodeExists for /collections/collection1/leaders/shard1
	at org.apache.solr.common.util.RetryUtil.retryOnThrowable(RetryUtil.java:40)
	at org.apache.solr.cloud.ShardLeaderElectionContextBase.runLeaderProcess(ElectionContext.java:123)
	... 46 more
Caused by: org.apache.zookeeper.KeeperException$NodeExistsException: KeeperErrorCode = NodeExists for /collections/collection1/leaders/shard1
	at org.apache.zookeeper.KeeperException.create(KeeperException.java:119)
	at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
	at org.apache.zookeeper.ZooKeeper.create(ZooKeeper.java:783)
	at org.apache.solr.common.cloud.SolrZkClient$10.execute(SolrZkClient.java:432)
	at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
	at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:429)
	at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:386)
	at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:373)
	at org.apache.solr.cloud.ShardLeaderElectionContextBase$1.execute(ElectionContext.java:128)
	at org.apache.solr.common.util.RetryUtil.retryOnThrowable(RetryUtil.java:34)
	... 47 more


REGRESSION:  org.apache.solr.cloud.SSLMigrationTest.testDistribSearch

Error Message:
Replica didn't have the proper urlScheme in the ClusterState

Stack Trace:
java.lang.AssertionError: Replica didn't have the proper urlScheme in the ClusterState
	at __randomizedtesting.SeedInfo.seed([1106F9229655B368:90E0773AE10AD354]:0)
	at org.junit.Assert.fail(Assert.java:93)
	at org.junit.Assert.assertTrue(Assert.java:43)
	at org.apache.solr.cloud.SSLMigrationTest.assertReplicaInformation(SSLMigrationTest.java:87)
	at org.apache.solr.cloud.SSLMigrationTest.testMigrateSSL(SSLMigrationTest.java:80)
	at org.apache.solr.cloud.SSLMigrationTest.doTest(SSLMigrationTest.java:57)
	at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:865)
	at sun.reflect.GeneratedMethodAccessor45.invoke(Unknown Source)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:606)
	at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1618)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:827)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:863)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:877)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
	at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:50)
	at org.apache.lucene.util.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 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 11113 lines...]
   [junit4] Suite: org.apache.solr.cloud.OverseerTest
   [junit4]   2> Creating dataDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux@2/solr/build/solr-core/test/J0/./solr.cloud.OverseerTest-1106F9229655B368-001/init-core-data-001
   [junit4]   2> 452956 T2522 oas.SolrTestCaseJ4.buildSSLConfig Randomized ssl (true) and clientAuth (true)
   [junit4]   2> 452956 T2522 oas.SolrTestCaseJ4.initCore ####initCore
   [junit4]   2> 452956 T2522 oas.SolrTestCaseJ4.initCore ####initCore end
   [junit4]   2> 452959 T2522 oas.SolrTestCaseJ4.setUp ###Starting testOverseerFailure
   [junit4]   2> 452960 T2522 oasc.ZkTestServer.run STARTING ZK TEST SERVER
   [junit4]   2> 452960 T2523 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
   [junit4]   2> 453060 T2522 oasc.ZkTestServer.run start zk server on port:36667
   [junit4]   2> 453061 T2522 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 456146 T2526 oazsp.FileTxnLog.commit WARN fsync-ing the write ahead log in SyncThread:0 took 3083ms which will adversely effect operation latency. See the ZooKeeper troubleshooting guide
   [junit4]   2> 456183 T2529 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@8a95f8 name:ZooKeeperConnection Watcher:127.0.0.1:36667 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 456183 T2522 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 456185 T2522 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 456186 T2531 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@bbcd1b name:ZooKeeperConnection Watcher:127.0.0.1:36667 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 456187 T2522 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 456187 T2522 oascc.SolrZkClient.makePath makePath: /solr
   [junit4]   2> 456190 T2522 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 456191 T2533 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@f06dc3 name:ZooKeeperConnection Watcher:127.0.0.1:36667/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 456191 T2522 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 456191 T2522 oascc.SolrZkClient.makePath makePath: /live_nodes
   [junit4]   2> 456192 T2522 oascc.SolrZkClient.makePath makePath: /clusterstate.json
   [junit4]   2> 456194 T2522 oascc.SolrZkClient.makePath makePath: /aliases.json
   [junit4]   2> 456195 T2522 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 456197 T2522 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 456198 T2535 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@73a177 name:ZooKeeperConnection Watcher:127.0.0.1:36667/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 456198 T2522 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 456199 T2522 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 456201 T2522 oascc.SolrZkClient.makePath makePath: /live_nodes/node1
   [junit4]   2> 456202 T2535 oascc.ZkStateReader$3.process Updating live nodes... (1)
   [junit4]   2> 456202 T2533 oascc.ZkStateReader$3.process Updating live nodes... (1)
   [junit4]   2> 456203 T2522 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 456204 T2537 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@a5ebc0 name:ZooKeeperConnection Watcher:127.0.0.1:36667/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 456204 T2522 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 456204 T2522 oascc.SolrZkClient.makePath makePath: /overseer_elect
   [junit4]   2> 456206 T2522 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
   [junit4]   2> 456209 T2522 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:36667_solr
   [junit4]   2> 456209 T2522 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
   [junit4]   2> 456211 T2522 oasc.Overseer.start Overseer (id=91671381612691460-127.0.0.1:36667_solr-n_0000000000) starting
   [junit4]   2> 456212 T2522 oascc.SolrZkClient.makePath makePath: /overseer/queue
   [junit4]   2> 456215 T2522 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
   [junit4]   2> 456219 T2522 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-failure
   [junit4]   2> 456222 T2522 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-running
   [junit4]   2> 456224 T2522 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-completed
   [junit4]   2> 456227 T2522 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
   [junit4]   2> 456230 T2539 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
   [junit4]   2> 456231 T2539 oasc.OverseerCollectionProcessor.prioritizeOverseerNodes prioritizing overseer nodes at 127.0.0.1:36667_solr
   [junit4]   2> 456231 T2538 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
   [junit4]   2> 457233 T2537 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 457235 T2538 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 457236 T2538 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> 457237 T2538 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1]
   [junit4]   2> 457237 T2538 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
   [junit4]   2> 457239 T2537 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 457240 T2533 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> 457240 T2535 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> 457733 T2522 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
   [junit4]   2> 457742 T2522 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 457747 T2537 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 457748 T2522 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 457748 T2538 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 457751 T2522 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
   [junit4]   2> 457751 T2537 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 457752 T2538 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"active",
   [junit4]   2> 	  "node_name":"node1",
   [junit4]   2> 	  "core":"core1",
   [junit4]   2> 	  "core_node_name":"core_node1",
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "numShards":"1",
   [junit4]   2> 	  "base_url":"http://node1/solr/"}
   [junit4]   2> 457753 T2538 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
   [junit4]   2> 457754 T2537 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 457855 T2533 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> 457855 T2535 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> 458909 T2522 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
   [junit4]   2> 458914 T2522 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 458915 T2541 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1ba41f7 name:ZooKeeperConnection Watcher:127.0.0.1:36667/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 458915 T2522 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 458916 T2538 oasc.Overseer$ClusterStateUpdater.run Overseer Loop exiting : 127.0.0.1:36667_solr
   [junit4]   2> 458917 T2542 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]   2> 458918 T2522 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:36667_solr
   [junit4]   2> 458919 T2522 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
   [junit4]   2> 458920 T2522 oasc.Overseer.start Overseer (id=91671381612691461-127.0.0.1:36667_solr-n_0000000001) starting
   [junit4]   2> 458929 T2544 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
   [junit4]   2> 458930 T2544 oasc.OverseerCollectionProcessor.prioritizeOverseerNodes prioritizing overseer nodes at 127.0.0.1:36667_solr
   [junit4]   2> 458930 T2543 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
   [junit4]   2> 458931 T2543 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 458932 T2543 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> 458932 T2543 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
   [junit4]   2> 458933 T2541 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 458934 T2533 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> 458934 T2535 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> 458987 T2541 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 458987 T2522 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
   [junit4]   2> 458988 T2543 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 458991 T2522 oasc.LeaderElector.checkIfIamLeader WARN Failed setting watch org.apache.zookeeper.KeeperException$NoNodeException: KeeperErrorCode = NoNode for /collections/collection1/leader_elect/shard1/election/91671381612691459-node1_core1-n_0000000002
   [junit4]   2> 	at org.apache.zookeeper.KeeperException.create(KeeperException.java:111)
   [junit4]   2> 	at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
   [junit4]   2> 	at org.apache.zookeeper.ZooKeeper.getData(ZooKeeper.java: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.LeaderElector.checkIfIamLeader(LeaderElector.java:127)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector.joinElection(LeaderElector.java:267)
   [junit4]   2> 	at org.apache.solr.cloud.OverseerTest$MockZKController.publishState(OverseerTest.java:155)
   [junit4]   2> 	at org.apache.solr.cloud.OverseerTest.testOverseerFailure(OverseerTest.java:661)
   [junit4]   2> 	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
   [junit4]   2> 	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
   [junit4]   2> 	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
   [junit4]   2> 	at java.lang.reflect.Method.invoke(Method.java:606)
   [junit4]   2> 	at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1618)
   [junit4]   2> 	at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:827)
   [junit4]   2> 	at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:863)
   [junit4]   2> 	at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:877)
   [junit4]   2> 	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
   [junit4]   2> 	at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:50)
   [junit4]   2> 	at org.apache.lucene.util.TestRuleFieldCacheSanity$1.evaluate(TestRuleFieldCacheSanity.java:51)
   [junit4]   2> 	at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
   [junit4]   2> 	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
   [junit4]   2> 	at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:49)
   [junit4]   2> 	at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:65)
   [junit4]   2> 	at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
   [junit4]   2> 	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
   [junit4]   2> 	at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:360)
   [junit4]   2> 	at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:793)
   [junit4]   2> 	at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:453)
   [junit4]   2> 	at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:836)
   [junit4]   2> 	at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:738)
   [junit4]   2> 	at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:772)
   [junit4]   2> 	at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:783)
   [junit4]   2> 	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
   [junit4]   2> 	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
   [junit4]   2> 	at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
   [junit4]   2> 	at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:42)
   [junit4]   2> 	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
   [junit4]   2> 	at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
   [junit4]   2> 	at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
   [junit4]   2> 	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
   [junit4]   2> 	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
   [junit4]   2> 	at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:43)
   [junit4]   2> 	at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
   [junit4]   2> 	at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:65)
   [junit4]   2> 	at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:55)
   [junit4]   2> 	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
   [junit4]   2> 	at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:360)
   [junit4]   2> 	at java.lang.Thread.run(Thread.java:744)
   [junit4]   2> 
   [junit4]   2> 458992 T2543 oasc.SolrException.log ERROR Problem cleaning up collection in zk:collection1:org.apache.zookeeper.KeeperException$NotEmptyException: KeeperErrorCode = Directory not empty for /collections/collection1/leader_elect/shard1/election
   [junit4]   2> 		at org.apache.zookeeper.KeeperException.create(KeeperException.java:125)
   [junit4]   2> 		at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
   [junit4]   2> 		at org.apache.zookeeper.ZooKeeper.delete(ZooKeeper.java:873)
   [junit4]   2> 		at org.apache.solr.common.cloud.SolrZkClient$2.execute(SolrZkClient.java:177)
   [junit4]   2> 		at org.apache.solr.common.cloud.SolrZkClient$2.execute(SolrZkClient.java:174)
   [junit4]   2> 		at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
   [junit4]   2> 		at org.apache.solr.common.cloud.SolrZkClient.delete(SolrZkClient.java:174)
   [junit4]   2> 		at org.apache.solr.common.cloud.SolrZkClient.clean(SolrZkClient.java:631)
   [junit4]   2> 		at org.apache.solr.common.cloud.SolrZkClient.clean(SolrZkClient.java:626)
   [junit4]   2> 		at org.apache.solr.common.cloud.SolrZkClient.clean(SolrZkClient.java:626)
   [junit4]   2> 		at org.apache.solr.common.cloud.SolrZkClient.clean(SolrZkClient.java:626)
   [junit4]   2> 		at org.apache.solr.cloud.Overseer$ClusterStateUpdater.removeCore(Overseer.java:1069)
   [junit4]   2> 		at org.apache.solr.cloud.Overseer$ClusterStateUpdater.processMessage(Overseer.java:342)
   [junit4]   2> 		at org.apache.solr.cloud.Overseer$ClusterStateUpdater.run(Overseer.java:241)
   [junit4]   2> 		at java.lang.Thread.run(Thread.java:744)
   [junit4]   2> 	
   [junit4]   2> 458991 T2535 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 458993 T2522 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 458994 T2541 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 458996 T2541 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 458997 T2535 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 458997 T2543 oasc.Overseer$ClusterStateUpdater.setShardLeader ERROR Could not mark shard leader for non existing collection:collection1
   [junit4]   2> 458999 T2541 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 459000 T2541 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 459001 T2543 oasc.Overseer$ClusterStateUpdater.setShardLeader ERROR Could not mark shard leader for non existing collection:collection1
   [junit4]   2> 459003 T2541 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 459106 T2533 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> 459106 T2535 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> 459995 T2522 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 460998 T2522 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 462001 T2522 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 463004 T2522 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 464006 T2522 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 465010 T2522 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 466012 T2522 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 467014 T2522 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 468017 T2522 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 469019 T2522 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 470022 T2522 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 471026 T2522 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 472028 T2522 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 473031 T2522 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 474034 T2522 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 474037 T2533 oascc.ZkStateReader$3.process Updating live nodes... (0)
   [junit4]   2> 474037 T2535 oascc.ZkStateReader$3.process Updating live nodes... (0)
   [junit4]   2> 474041 T2522 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:36667 36667
   [junit4]   2> 474234 T2523 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:36667 36667
   [junit4]   2> 474236 T2522 oas.SolrTestCaseJ4.tearDown ###Ending testOverseerFailure
   [junit4]   2> 474236 T2543 oasc.Overseer$ClusterStateUpdater.run Overseer Loop exiting : 127.0.0.1:36667_solr
   [junit4]   2> 474241 T2545 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> NOTE: reproduce with: ant test  -Dtestcase=OverseerTest -Dtests.method=testOverseerFailure -Dtests.seed=1106F9229655B368 -Dtests.multiplier=3 -Dtests.slow=true -Dtests.locale=en_MT -Dtests.timezone=Etc/GMT+12 -Dtests.file.encoding=UTF-8
   [junit4] ERROR   21.3s J0 | OverseerTest.testOverseerFailure <<<
   [junit4]    > Throwable #1: org.apache.solr.common.SolrException: Could not register as the leader because creating the ephemeral registration node in ZooKeeper failed
   [junit4]    > 	at __randomizedtesting.SeedInfo.seed([1106F9229655B368:150E76D184F05C49]:0)
   [junit4]    > 	at org.apache.solr.cloud.ShardLeaderElectionContextBase.runLeaderProcess(ElectionContext.java:136)
   [junit4]    > 	at org.apache.solr.cloud.LeaderElector.runIamLeaderProcess(LeaderElector.java:142)
   [junit4]    > 	at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:110)
   [junit4]    > 	at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:134)
   [junit4]    > 	at org.apache.solr.cloud.LeaderElector.joinElection(LeaderElector.java:267)
   [junit4]    > 	at org.apache.solr.cloud.OverseerTest$MockZKController.publishState(OverseerTest.java:155)
   [junit4]    > 	at org.apache.solr.cloud.OverseerTest.testOverseerFailure(OverseerTest.java:661)
   [junit4]    > 	at java.lang.Thread.run(Thread.java:744)
   [junit4]    > Caused by: org.apache.solr.common.SolrException: org.apache.zookeeper.KeeperException$NodeExistsException: KeeperErrorCode = NodeExists for /collections/collection1/leaders/shard1
   [junit4]    > 	at org.apache.solr.common.util.RetryUtil.retryOnThrowable(RetryUtil.java:40)
   [junit4]    > 	at org.apache.solr.cloud.ShardLeaderElectionContextBase.runLeaderProcess(ElectionContext.java:123)
   [junit4]    > 	... 46 more
   [junit4]    > Caused by: org.apache.zookeeper.KeeperException$NodeExistsException: KeeperErrorCode = NodeExists for /collections/collection1/leaders/shard1
   [junit4]    > 	at org.apache.zookeeper.KeeperException.create(KeeperException.java:119)
   [junit4]    > 	at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
   [junit4]    > 	at org.apache.zookeeper.ZooKeeper.create(ZooKeeper.java:783)
   [junit4]    > 	at org.apache.solr.common.cloud.SolrZkClient$10.execute(SolrZkClient.java:432)
   [junit4]    > 	at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
   [junit4]    > 	at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:429)
   [junit4]    > 	at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:386)
   [junit4]    > 	at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:373)
   [junit4]    > 	at org.apache.solr.cloud.ShardLeaderElectionContextBase$1.execute(ElectionContext.java:128)
   [junit4]    > 	at org.apache.solr.common.util.RetryUtil.retryOnThrowable(RetryUtil.java:34)
   [junit4]    > 	... 47 more
   [junit4]   2> 474268 T2522 oas.SolrTestCaseJ4.setUp ###Starting testPlaceholders
   [junit4]   2> 474269 T2522 oasc.ZkTestServer.run STARTING ZK TEST SERVER
   [junit4]   2> 474270 T2546 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
   [junit4]   2> 474370 T2522 oasc.ZkTestServer.run start zk server on port:47205
   [junit4]   2> 474371 T2522 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 474427 T2552 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1de0bab name:ZooKeeperConnection Watcher:127.0.0.1:47205/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 474428 T2522 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 474428 T2522 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 474430 T2554 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@c6a4aa name:ZooKeeperConnection Watcher:127.0.0.1:47205 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 474430 T2522 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 474434 T2522 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 474434 T2556 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@c6eb5c name:ZooKeeperConnection Watcher:127.0.0.1:47205 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 474435 T2522 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 474435 T2522 oascc.SolrZkClient.makePath makePath: /solr
   [junit4]   2> 474439 T2522 oascc.SolrZkClient.makePath makePath: /live_nodes
   [junit4]   2> 474439 T2547 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x145aea31c560002, 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> 474441 T2522 oascc.SolrZkClient.makePath makePath: /clusterstate.json
   [junit4]   2> 474443 T2522 oascc.SolrZkClient.makePath makePath: /aliases.json
   [junit4]   2> 474445 T2522 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 474447 T2522 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 474448 T2558 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@cb075b name:ZooKeeperConnection Watcher:127.0.0.1:47205/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 474448 T2522 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 474449 T2522 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 474450 T2522 oascc.SolrZkClient.makePath makePath: /live_nodes/node1
   [junit4]   2> 474456 T2552 oascc.ZkStateReader$3.process Updating live nodes... (1)
   [junit4]   2> 474456 T2558 oascc.ZkStateReader$3.process Updating live nodes... (1)
   [junit4]   2> 474457 T2522 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 474458 T2560 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1fd3367 name:ZooKeeperConnection Watcher:127.0.0.1:47205/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 474459 T2522 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 474459 T2522 oascc.SolrZkClient.makePath makePath: /overseer_elect
   [junit4]   2> 474461 T2522 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
   [junit4]   2> 474467 T2522 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:47205_solr
   [junit4]   2> 474467 T2522 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
   [junit4]   2> 474468 T2522 oasc.Overseer.start Overseer (id=91671383009263620-127.0.0.1:47205_solr-n_0000000000) starting
   [junit4]   2> 474472 T2522 oascc.SolrZkClient.makePath makePath: /overseer/queue
   [junit4]   2> 474475 T2522 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
   [junit4]   2> 474478 T2522 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-failure
   [junit4]   2> 474482 T2522 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-running
   [junit4]   2> 474487 T2522 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-completed
   [junit4]   2> 474492 T2522 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
   [junit4]   2> 474495 T2562 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
   [junit4]   2> 474495 T2561 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
   [junit4]   2> 474495 T2562 oasc.OverseerCollectionProcessor.prioritizeOverseerNodes prioritizing overseer nodes at 127.0.0.1:47205_solr
   [junit4]   2> 474497 T2560 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 474497 T2561 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 474498 T2561 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> 474498 T2561 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1, shard2, shard3, shard4, shard5, shard6, shard7, shard8, shard9, shard10, shard11, shard12]
   [junit4]   2> 474498 T2561 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard7
   [junit4]   2> 474499 T2560 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 474500 T2558 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> 474500 T2552 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> 474997 T2522 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard7/election
   [junit4]   2> 475005 T2522 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard7
   [junit4]   2> 475010 T2560 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 475011 T2522 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 475012 T2561 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 475013 T2552 oascc.ZkStateReader$3.process Updating live nodes... (0)
   [junit4]   2> 475013 T2558 oascc.ZkStateReader$3.process Updating live nodes... (0)
   [junit4]   2> 475015 T2522 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:47205 47205
   [junit4]   2> 475097 T2546 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:47205 47205
   [junit4]   2> 475098 T2522 oas.SolrTestCaseJ4.tearDown ###Ending testPlaceholders
   [junit4]   1> client port:0.0.0.0/0.0.0.0:0
   [junit4]   2> 475101 T2561 oasc.Overseer$ClusterStateUpdater.run Overseer Loop exiting : 127.0.0.1:47205_solr
   [junit4]   2> 475102 T2563 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]   2> 475104 T2522 oas.SolrTestCaseJ4.setUp ###Starting testShardAssignment
   [junit4]   2> 475105 T2522 oasc.ZkTestServer.run STARTING ZK TEST SERVER
   [junit4]   2> 475106 T2564 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
   [junit4]   2> 475206 T2522 oasc.ZkTestServer.run start zk server on port:59202
   [junit4]   2> 475206 T2522 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 475212 T2570 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@828c1e name:ZooKeeperConnection Watcher:127.0.0.1:59202 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 475213 T2522 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 475215 T2522 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 475217 T2572 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@e07cd0 name:ZooKeeperConnection Watcher:127.0.0.1:59202 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 475217 T2522 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 475217 T2522 oascc.SolrZkClient.makePath makePath: /solr
   [junit4]   2> 475220 T2522 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 475222 T2574 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@13868be name:ZooKeeperConnection Watcher:127.0.0.1:59202/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 475222 T2522 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 475222 T2522 oascc.SolrZkClient.makePath makePath: /live_nodes
   [junit4]   2> 475226 T2522 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 475227 T2576 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@17f4ed7 name:ZooKeeperConnection Watcher:127.0.0.1:59202/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 475227 T2522 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 475228 T2522 oascc.SolrZkClient.makePath makePath: /overseer_elect
   [junit4]   2> 475231 T2522 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
   [junit4]   2> 475238 T2522 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:59202_solr
   [junit4]   2> 475239 T2522 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
   [junit4]   2> 475240 T2522 oasc.Overseer.start Overseer (id=91671383063986179-127.0.0.1:59202_solr-n_0000000000) starting
   [junit4]   2> 475242 T2522 oascc.SolrZkClient.makePath makePath: /overseer/queue
   [junit4]   2> 475244 T2522 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
   [junit4]   2> 475249 T2522 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-failure
   [junit4]   2> 475251 T2522 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-running
   [junit4]   2> 475256 T2522 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-completed
   [junit4]   2> 475261 T2522 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
   [junit4]   2> 475266 T2578 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
   [junit4]   2> 475266 T2522 oascc.SolrZkClient.makePath makePath: /clusterstate.json
   [junit4]   2> 475267 T2578 oasc.OverseerCollectionProcessor.prioritizeOverseerNodes prioritizing overseer nodes at 127.0.0.1:59202_solr
   [junit4]   2> 475267 T2577 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
   [junit4]   2> 475268 T2522 oascc.SolrZkClient.makePath makePath: /aliases.json
   [junit4]   2> 475269 T2522 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 475272 T2522 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 475273 T2580 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@4ddb78 name:ZooKeeperConnection Watcher:127.0.0.1:59202/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 475273 T2522 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 475274 T2522 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 475275 T2522 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1
   [junit4]   2> 475279 T2574 oascc.ZkStateReader$3.process Updating live nodes... (1)
   [junit4]   2> 475280 T2580 oascc.ZkStateReader$3.process Updating live nodes... (1)
   [junit4]   2> 475281 T2576 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 475282 T2577 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 475282 T2577 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> 475283 T2577 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1, shard2, shard3]
   [junit4]   2> 475283 T2577 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard3
   [junit4]   2> 475286 T2576 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 475287 T2574 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> 475287 T2580 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> 475781 T2522 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard3/election
   [junit4]   2> 475787 T2522 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard3
   [junit4]   2> 475792 T2576 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 475794 T2576 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 475794 T2577 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 475798 T2577 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> 475798 T2577 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
   [junit4]   2> 475798 T2577 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard2
   [junit4]   2> 475802 T2576 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 475903 T2580 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> 475903 T2574 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> 476294 T2522 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard2/election
   [junit4]   2> 476300 T2522 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard2
   [junit4]   2> 476304 T2576 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 476304 T2576 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 476304 T2576 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 476306 T2577 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 476307 T2576 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 476308 T2577 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> 476308 T2577 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
   [junit4]   2> 476308 T2577 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
   [junit4]   2> 476310 T2576 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 476412 T2574 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> 476412 T2580 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> 476805 T2522 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
   [junit4]   2> 476811 T2522 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 476815 T2576 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 476815 T2576 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 476815 T2576 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 476816 T2576 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 476817 T2577 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 476819 T2577 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> 476819 T2577 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
   [junit4]   2> 476820 T2577 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard3
   [junit4]   2> 476821 T2576 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 476923 T2574 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> 476923 T2580 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> 477316 T2522 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard3/election
   [junit4]   2> 477329 T2576 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 477329 T2576 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 477329 T2576 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 477331 T2577 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 477331 T2577 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> 477332 T2577 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
   [junit4]   2> 477332 T2577 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard2
   [junit4]   2> 477334 T2576 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 477436 T2580 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> 477436 T2574 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> 477829 T2522 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard2/election
   [junit4]   2> 477841 T2576 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 477842 T2576 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 477842 T2576 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 477845 T2577 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 477846 T2577 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> 477847 T2577 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
   [junit4]   2> 477847 T2577 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
   [junit4]   2> 477850 T2576 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 477954 T2580 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> 477954 T2574 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> 478342 T2522 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
   [junit4]   2> 478350 T2580 oascc.ZkStateReader$3.process Updating live nodes... (0)
   [junit4]   2> 478351 T2580 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> 478352 T2580 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> 478352 T2522 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:59202 59202
   [junit4]   2> 478352 T2580 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> 478495 T2564 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:59202 59202
   [junit4]   2> 478497 T2522 oas.SolrTestCaseJ4.tearDown ###Ending testShardAssignment
   [junit4]   2> 478497 T2577 oasc.Overseer$ClusterStateUpdater.run Overseer Loop exiting : 127.0.0.1:59202_solr
   [junit4]   1> client port:0.0.0.0/0.0.0.0:0
   [junit4]   2> 478502 T2581 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]   2> 478502 T2522 oas.SolrTestCaseJ4.setUp ###Starting testShardLeaderChange
   [junit4]   2> 478503 T2522 oasc.ZkTestServer.run STARTING ZK TEST SERVER
   [junit4]   2> 478504 T2582 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
   [junit4]   2> 478604 T2522 oasc.ZkTestServer.run start zk server on port:43449
   [junit4]   2> 478606 T2522 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 478611 T2588 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@e1244d name:ZooKeeperConnection Watcher:127.0.0.1:43449/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 478612 T2522 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 478612 T2522 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 478614 T2590 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@b97448 name:ZooKeeperConnection Watcher:127.0.0.1:43449 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 478614 T2522 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 478617 T2522 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 478618 T2592 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1a69e3c name:ZooKeeperConnection Watcher:127.0.0.1:43449 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 478619 T2522 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 478619 T2522 oascc.SolrZkClient.makePath makePath: /solr
   [junit4]   2> 478622 T2522 oascc.SolrZkClient.makePath makePath: /live_nodes
   [junit4]   2> 478625 T2593 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 478626 T2522 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 478627 T2596 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1e6a867 name:ZooKeeperConnection Watcher:127.0.0.1:43449/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 478627 T2593 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 478627 T2597 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1458fd7 name:ZooKeeperConnection Watcher:127.0.0.1:43449/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 478628 T2522 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 478628 T2593 oascc.SolrZkClient.makePath makePath: /overseer_elect
   [junit4]   2> 478629 T2522 oascc.SolrZkClient.makePath makePath: /clusterstate.json
   [junit4]   2> 478630 T2593 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
   [junit4]   2> 478631 T2522 oascc.SolrZkClient.makePath makePath: /aliases.json
   [junit4]   2> 478632 T2522 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 478634 T2593 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:43449_solr
   [junit4]   2> 478634 T2593 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
   [junit4]   2> 478639 T2522 oascc.SolrZkClient.makePath makePath: /live_nodes/node1
   [junit4]   2> 478640 T2593 oasc.Overseer.start Overseer (id=91671383286743043-127.0.0.1:43449_solr-n_0000000000) starting
   [junit4]   2> 478643 T2593 oascc.SolrZkClient.makePath makePath: /overseer/queue
   [junit4]   2> 478644 T2597 oascc.ZkStateReader$3.process Updating live nodes... (1)
   [junit4]   2> 478644 T2522 oascc.SolrZkClient.makePath makePath: /overseer/queue
   [junit4]   2> 478653 T2593 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
   [junit4]   2> 478656 T2593 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-failure
   [junit4]   2> 478658 T2593 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-running
   [junit4]   2> 478660 T2593 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-completed
   [junit4]   2> 478662 T2593 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
   [junit4]   2> 478669 T2599 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
   [junit4]   2> 478669 T2593 oasc.OverseerTest$OverseerRestarter.run Killing overseer.
   [junit4]   2> 478671 T2599 oasc.OverseerCollectionProcessor.prioritizeOverseerNodes prioritizing overseer nodes at 127.0.0.1:43449_solr
   [junit4]   2> 478671 T2599 oasc.OverseerCollectionProcessor.run ERROR Unable to prioritize overseer  org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /roles.json
   [junit4]   2> 	at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
   [junit4]   2> 	at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
   [junit4]   2> 	at org.apache.zookeeper.ZooKeeper.exists(ZooKeeper.java:1045)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient$4.execute(SolrZkClient.java:226)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient$4.execute(SolrZkClient.java:223)
   [junit4]   2> 	at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient.exists(SolrZkClient.java:223)
   [junit4]   2> 	at org.apache.solr.cloud.OverseerCollectionProcessor.prioritizeOverseerNodes(OverseerCollectionProcessor.java:299)
   [junit4]   2> 	at org.apache.solr.cloud.OverseerCollectionProcessor.run(OverseerCollectionProcessor.java:212)
   [junit4]   2> 	at java.lang.Thread.run(Thread.java:744)
   [junit4]   2> 
   [junit4]   2> 478671 T2593 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 478672 T2599 oasc.OverseerCollectionProcessor.amILeader  org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /overseer_elect/leader
   [junit4]   2> 	at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
   [junit4]   2> 	at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
   [junit4]   2> 	at org.apache.zookeeper.ZooKeeper.getData(ZooKeeper.java: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.OverseerCollectionProcessor.amILeader(OverseerCollectionProcessor.java:432)
   [junit4]   2> 	at org.apache.solr.cloud.OverseerCollectionProcessor.run(OverseerCollectionProcessor.java:219)
   [junit4]   2> 	at java.lang.Thread.run(Thread.java:744)
   [junit4]   2> 
   [junit4]   2> 478673 T2599 oasc.OverseerCollectionProcessor.amILeader According to ZK I (id=91671383286743043-127.0.0.1:43449_solr-n_0000000000) am no longer a leader.
   [junit4]   2> 478674 T2601 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1b94277 name:ZooKeeperConnection Watcher:127.0.0.1:43449/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 478674 T2593 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 478679 T2593 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:43449_solr
   [junit4]   2> 478679 T2593 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
   [junit4]   2> 478683 T2593 oasc.Overseer.start Overseer (id=91671383286743045-127.0.0.1:43449_solr-n_0000000001) starting
   [junit4]   2> 478695 T2603 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
   [junit4]   2> 478697 T2603 oasc.OverseerCollectionProcessor.prioritizeOverseerNodes prioritizing overseer nodes at 127.0.0.1:43449_solr
   [junit4]   2> 478698 T2602 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
   [junit4]   2> 478701 T2602 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 478701 T2602 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"state1",
   [junit4]   2> 	  "node_name":"node1",
   [junit4]   2> 	  "core":"core1",
   [junit4]   2> 	  "core_node_name":"node1",
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "numShards":"1",
   [junit4]   2> 	  "base_url":"http://node1/solr/"}
   [junit4]   2> 478701 T2602 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1]
   [junit4]   2> 478702 T2602 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
   [junit4]   2> 478705 T2601 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 478705 T2597 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> 479153 T2522 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
   [junit4]   2> 479162 T2522 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 479170 T2601 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 479171 T2602 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 479172 T2601 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 479172 T2522 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
   [junit4]   2> 479174 T2602 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"state2",
   [junit4]   2> 	  "node_name":"node1",
   [junit4]   2> 	  "core":"core1",
   [junit4]   2> 	  "core_node_name":"node1",
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "numShards":"1",
   [junit4]   2> 	  "base_url":"http://node1/solr/"}
   [junit4]   2> 479174 T2602 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
   [junit4]   2> 479175 T2601 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 479184 T2522 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 479185 T2605 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1cfe5b1 name:ZooKeeperConnection Watcher:127.0.0.1:43449/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 479186 T2522 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 479186 T2522 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 479188 T2522 oascc.SolrZkClient.makePath makePath: /live_nodes/node2
   [junit4]   2> 479193 T2597 oascc.ZkStateReader$3.process Updating live nodes... (2)
   [junit4]   2> 479194 T2605 oascc.ZkStateReader$3.process Updating live nodes... (2)
   [junit4]   2> 479197 T2601 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 479197 T2522 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
   [junit4]   2> 479202 T2602 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"state1",
   [junit4]   2> 	  "node_name":"node1",
   [junit4]   2> 	  "core":"core1",
   [junit4]   2> 	  "core_node_name":"node1",
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "numShards":"1",
   [junit4]   2> 	  "base_url":"http://node1/solr/"}
   [junit4]   2> 479202 T2602 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
   [junit4]   2> 479204 T2522 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 479204 T2601 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 479306 T2605 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
   [junit4]   2> 479306 T2597 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
   [junit4]   2> 479405 T2522 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 479407 T2601 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 479408 T2601 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 479408 T2601 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 479409 T2602 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 479410 T2602 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"state2",
   [junit4]   2> 	  "node_name":"node2",
   [junit4]   2> 	  "core":"core4",
   [junit4]   2> 	  "core_node_name":"node2",
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "numShards":"1",
   [junit4]   2> 	  "base_url":"http://node2/solr/"}
   [junit4]   2> 479410 T2602 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=1
   [junit4]   2> 479410 T2602 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
   [junit4]   2> 479412 T2601 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 479517 T2597 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
   [junit4]   2> 479517 T2605 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
   [junit4]   2> 479908 T2522 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
   [junit4]   2> 479914 T2597 oascc.ZkStateReader$3.process Updating live nodes... (1)
   [junit4]   2> 479914 T2605 oascc.ZkStateReader$3.process Updating live nodes... (1)
   [junit4]   2> 479915 T2583 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x145aea32ce00004, likely client has closed socket
   [junit4]   2> 	at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:228)
   [junit4] 

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

  [junit4]   2> 	at org.apache.solr.cloud.LeaderElector.runIamLeaderProcess(LeaderElector.java:142)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:110)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector.joinElection(LeaderElector.java:267)
   [junit4]   2> 	at org.apache.solr.cloud.ShardLeaderElectionContext.rejoinLeaderElection(ElectionContext.java:372)
   [junit4]   2> 	at org.apache.solr.cloud.ShardLeaderElectionContext.runLeaderProcess(ElectionContext.java:210)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector.runIamLeaderProcess(LeaderElector.java:142)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:110)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector.joinElection(LeaderElector.java:267)
   [junit4]   2> 	at org.apache.solr.cloud.ShardLeaderElectionContext.rejoinLeaderElection(ElectionContext.java:372)
   [junit4]   2> 	at org.apache.solr.cloud.ShardLeaderElectionContext.runLeaderProcess(ElectionContext.java:210)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector.runIamLeaderProcess(LeaderElector.java:142)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:110)
   [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> Caused by: org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /overseer/queue
   [junit4]   2> 	at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
   [junit4]   2> 	at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
   [junit4]   2> 	at org.apache.zookeeper.ZooKeeper.exists(ZooKeeper.java:1045)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient$4.execute(SolrZkClient.java:226)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient$4.execute(SolrZkClient.java:223)
   [junit4]   2> 	at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient.exists(SolrZkClient.java:223)
   [junit4]   2> 	at org.apache.solr.common.cloud.ZkCmdExecutor.ensureExists(ZkCmdExecutor.java:100)
   [junit4]   2> 	at org.apache.solr.common.cloud.ZkCmdExecutor.ensureExists(ZkCmdExecutor.java:94)
   [junit4]   2> 	at org.apache.solr.cloud.DistributedQueue.<init>(DistributedQueue.java:68)
   [junit4]   2> 	... 19 more
   [junit4]   2> 
   [junit4]   2> 1294721 T5526 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
   [junit4]   2> 1294721 T5526 oasc.LeaderElector$ElectionWatcher.process WARN  org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /overseer_elect/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> NOTE: leaving temporary files on disk at: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux@2/solr/build/solr-core/test/J1/./solr.cloud.SSLMigrationTest-1106F9229655B368-001
   [junit4]   2> NOTE: test params are: codec=Lucene46: {}, docValues:{}, sim=RandomSimilarityProvider(queryNorm=false,coord=crazy): {}, locale=ar_OM, timezone=America/Goose_Bay
   [junit4]   2> NOTE: Linux 3.8.0-38-generic i386/Oracle Corporation 1.7.0_60-ea (32-bit)/cpus=8,threads=1,free=231244656,total=383348736
   [junit4]   2> NOTE: All tests run in this JVM: [FieldAnalysisRequestHandlerTest, LeaderElectionIntegrationTest, CollectionsAPIDistributedZkTest, TestSolrQueryParserDefaultOperatorResource, BJQParserTest, TestStressRecovery, AssignTest, TestRandomFaceting, SolrRequestParserTest, DebugComponentTest, SolrCmdDistributorTest, RequiredFieldsTest, TestUniqueKeyFieldResource, TestFastLRUCache, NoCacheHeaderTest, TestAtomicUpdateErrorCases, TestBinaryField, TestFastOutputStream, TestNumberUtils, TestSweetSpotSimilarityFactory, TestSolr4Spatial, TestCSVResponseWriter, TestFileDictionaryLookup, SimplePostToolTest, OverseerRolesTest, TestDistributedGrouping, FullSolrCloudDistribCmdsTest, TestManagedStopFilterFactory, TestFiltering, TestRangeQuery, TestSolrQueryParserResource, TestBinaryResponseWriter, TestHashPartitioner, IndexBasedSpellCheckerTest, SignatureUpdateProcessorFactoryTest, OpenCloseCoreStressTest, TestComponentsName, TestComplexPhraseQParserPlugin, TestStressLucene, PrimUtilsTest, TestWordDelimiterFilterFactory, TestNonDefinedSimilarityFactory, TestCloudManagedSchema, ShardRoutingCustomTest, SpellCheckCollatorTest, HdfsSyncSliceTest, SpellCheckComponentTest, DisMaxRequestHandlerTest, TestUpdate, ChaosMonkeySafeLeaderTest, TestReloadAndDeleteDocs, TestPhraseSuggestions, IndexSchemaRuntimeFieldTest, UniqFieldsUpdateProcessorFactoryTest, DocValuesMultiTest, TestCollationField, TestOmitPositions, TestLazyCores, PingRequestHandlerTest, BadIndexSchemaTest, TestCollectionAPI, TestIndexingPerformance, StressHdfsTest, ZkSolrClientTest, DeleteShardTest, HdfsCollectionsAPIDistributedZkTest, BlockDirectoryTest, TestCodecSupport, SolrIndexConfigTest, TimeZoneUtilsTest, MigrateRouteKeyTest, AsyncMigrateRouteKeyTest, OpenExchangeRatesOrgProviderTest, NotRequiredUniqueKeyTest, TestUtils, TestFoldingMultitermQuery, DocValuesMissingTest, SolrCoreCheckLockOnStartupTest, TestQuerySenderListener, TestDistributedSearch, CurrencyFieldXmlFileTest, BadCopyFieldTest, TestCloudManagedSchemaAddField, AlternateDirectoryTest, AddSchemaFieldsUpdateProcessorFactoryTest, TestRTGBase, HdfsUnloadDistributedZkTest, TestCSVLoader, TestZkChroot, BasicZkTest, NumericFieldsTest, DateFieldTest, DirectUpdateHandlerTest, AddBlockUpdateTest, ConvertedLegacyTest, ChaosMonkeyNothingIsSafeTest, TestPartialUpdateDeduplication, AutoCommitTest, TermVectorComponentDistributedTest, TestStressReorder, TestMultiCoreConfBootstrap, TestReload, TestStressVersions, StatsComponentTest, PeerSyncTest, TestFunctionQuery, BasicFunctionalityTest, TestIndexSearcher, HighlighterTest, TestCoreDiscovery, SuggesterFSTTest, SpatialFilterTest, WordBreakSolrSpellCheckerTest, FieldMutatingUpdateProcessorTest, StatelessScriptUpdateProcessorFactoryTest, TestRemoteStreaming, XsltUpdateRequestHandlerTest, StandardRequestHandlerTest, TestReversedWildcardFilterFactory, TestQueryTypes, TermsComponentTest, RequestHandlersTest, TestValueSourceCache, TermVectorComponentTest, TestArbitraryIndexDir, SolrPluginUtilsTest, UpdateRequestProcessorFactoryTest, MBeansHandlerTest, JsonLoaderTest, CSVRequestHandlerTest, TestLFUCache, SOLR749Test, TestSolrIndexConfig, CopyFieldTest, TestMergePolicyConfig, MultiTermTest, TestDocSet, TestElisionMultitermQuery, TestFuzzyAnalyzedSuggestions, ExternalFileFieldSortTest, DirectSolrConnectionTest, TestXIncludeConfig, TestPerFieldSimilarity, TestIBSimilarityFactory, TestFastWriter, TestJmxMonitoredMap, PluginInfoTest, TestSystemIdResolver, TestSuggestSpellingConverter, DOMUtilTest, ClusterStateTest, ZkNodePropsTest, FileUtilsTest, SolrTestCaseJ4Test, TestCursorMarkWithoutUniqueKey, TestDistributedMissingSort, TestHighlightDedupGrouping, TestCollationKeyRangeQueries, AliasIntegrationTest, ConnectionManagerTest, DistribCursorPagingTest, RemoteQueryErrorTest, SSLMigrationTest]
   [junit4] Completed on J1 in 35.41s, 1 test, 1 failure <<< FAILURES!

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

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



Mime
View raw message