You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@lucene.apache.org by Policeman Jenkins Server <je...@thetaphi.de> on 2014/05/13 01:39:24 UTC
[JENKINS] Lucene-Solr-4.x-Linux (64bit/jdk1.8.0_20-ea-b11) - Build
# 10176 - Still Failing!
Build: http://jenkins.thetaphi.de/job/Lucene-Solr-4.x-Linux/10176/
Java: 64bit/jdk1.8.0_20-ea-b11 -XX:+UseCompressedOops -XX:+UseConcMarkSweepGC
1 tests failed.
REGRESSION: org.apache.solr.cloud.OverseerTest.testOverseerFailure
Error Message:
KeeperErrorCode = NoNode for /collections/collection1/leader_elect/shard1/election
Stack Trace:
org.apache.zookeeper.KeeperException$NoNodeException: KeeperErrorCode = NoNode for /collections/collection1/leader_elect/shard1/election
at __randomizedtesting.SeedInfo.seed([BBD14D8DFBF4FAB:FB59B2BCD1AA08A]:0)
at org.apache.zookeeper.KeeperException.create(KeeperException.java:111)
at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
at org.apache.zookeeper.ZooKeeper.getChildren(ZooKeeper.java:1472)
at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:260)
at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:257)
at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
at org.apache.solr.common.cloud.SolrZkClient.getChildren(SolrZkClient.java:257)
at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:94)
at org.apache.solr.cloud.LeaderElector.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:62)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:483)
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 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:745)
Build Log:
[...truncated 11089 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-BBD14D8DFBF4FAB-001/init-core-data-001
[junit4] 2> 58176 T285 oas.SolrTestCaseJ4.buildSSLConfig Randomized ssl (true) and clientAuth (true)
[junit4] 2> 58176 T285 oas.SolrTestCaseJ4.initCore ####initCore
[junit4] 2> 58177 T285 oas.SolrTestCaseJ4.initCore ####initCore end
[junit4] 2> 58179 T285 oas.SolrTestCaseJ4.setUp ###Starting testReplay
[junit4] 2> 58180 T285 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4] 1> client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 58181 T286 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4] 2> 58281 T285 oasc.ZkTestServer.run start zk server on port:39031
[junit4] 2> 58282 T285 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 58308 T292 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@87c7726 name:ZooKeeperConnection Watcher:127.0.0.1:39031/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 58308 T285 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 58309 T285 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 58311 T294 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@7f4ecd52 name:ZooKeeperConnection Watcher:127.0.0.1:39031 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 58312 T285 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 58314 T285 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 58315 T296 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@6381161 name:ZooKeeperConnection Watcher:127.0.0.1:39031 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 58315 T285 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 58315 T285 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 58318 T285 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4] 2> 58321 T285 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4] 2> 58322 T285 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4] 2> 58323 T285 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 58326 T285 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4] 2> 58331 T285 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 58333 T298 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@6d1693c7 name:ZooKeeperConnection Watcher:127.0.0.1:39031/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 58333 T285 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 58334 T285 oascc.SolrZkClient.makePath makePath: /overseer_elect
[junit4] 2> 58336 T285 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4] 2> 58339 T285 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:39031_solr
[junit4] 2> 58340 T285 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 58342 T285 oasc.Overseer.start Overseer (id=91746254707884035-127.0.0.1:39031_solr-n_0000000000) starting
[junit4] 2> 58343 T285 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4] 2> 58348 T285 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-failure
[junit4] 2> 58351 T285 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-running
[junit4] 2> 58356 T285 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-completed
[junit4] 2> 58361 T285 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4] 2> 58368 T300 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 58369 T300 oasc.OverseerCollectionProcessor.prioritizeOverseerNodes prioritizing overseer nodes at 127.0.0.1:39031_solr
[junit4] 2> 58371 T299 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 58372 T299 oasc.Overseer$ClusterStateUpdater.run Replaying operations from work queue.
[junit4] 2> 58372 T299 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=null message={
[junit4] 2> "operation":"state",
[junit4] 2> "base_url":"http://127.0.0.1/solr",
[junit4] 2> "node_name":"node1",
[junit4] 2> "shard":"s1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "core":"core1",
[junit4] 2> "roles":"",
[junit4] 2> "state":"recovering"}
[junit4] 2> 58374 T292 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 0)
[junit4] 2> 58377 T299 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=null message={
[junit4] 2> "operation":"state",
[junit4] 2> "base_url":"http://127.0.0.1/solr",
[junit4] 2> "node_name":"node1",
[junit4] 2> "shard":"s1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "core":"core2",
[junit4] 2> "roles":"",
[junit4] 2> "state":"recovering"}
[junit4] 2> 58378 T292 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 0)
[junit4] 2> 58381 T299 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 58383 T299 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 58383 T299 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=null message={
[junit4] 2> "operation":"state",
[junit4] 2> "base_url":"http://127.0.0.1/solr",
[junit4] 2> "node_name":"node1",
[junit4] 2> "shard":"s1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "core":"core3",
[junit4] 2> "roles":"",
[junit4] 2> "state":"recovering"}
[junit4] 2> 58386 T298 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 58387 T292 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 0)
[junit4] 2> 58473 T285 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:39031 39031
[junit4] 2> 58627 T286 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:39031 39031
[junit4] 2> 58628 T285 oas.SolrTestCaseJ4.tearDown ###Ending testReplay
[junit4] 2> 58629 T299 oasc.Overseer$ClusterStateUpdater.run Overseer Loop exiting : 127.0.0.1:39031_solr
[junit4] 2> 58629 T301 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> 58632 T285 oas.SolrTestCaseJ4.setUp ###Starting testDoubleAssignment
[junit4] 2> 58632 T285 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4] 1> client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 58633 T302 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4] 2> 58733 T285 oasc.ZkTestServer.run start zk server on port:52582
[junit4] 2> 58734 T285 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 58738 T308 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@59c2d36a name:ZooKeeperConnection Watcher:127.0.0.1:52582/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 58739 T285 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 58739 T285 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 58741 T310 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1fb7722a name:ZooKeeperConnection Watcher:127.0.0.1:52582 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 58741 T285 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 58743 T285 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 58744 T312 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@466642b0 name:ZooKeeperConnection Watcher:127.0.0.1:52582 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 58744 T285 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 58745 T285 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 58747 T285 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4] 2> 58749 T285 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4] 2> 58750 T285 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4] 2> 58751 T285 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 58755 T285 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 58757 T314 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@7dddfdb1 name:ZooKeeperConnection Watcher:127.0.0.1:52582/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 58757 T285 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 58758 T285 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 58760 T285 oascc.SolrZkClient.makePath makePath: /live_nodes/node1
[junit4] 2> 58761 T308 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 58762 T314 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 58762 T285 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 58764 T316 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@32cb28e3 name:ZooKeeperConnection Watcher:127.0.0.1:52582/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 58764 T285 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 58765 T285 oascc.SolrZkClient.makePath makePath: /overseer_elect
[junit4] 2> 58767 T285 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4] 2> 58769 T285 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:52582_solr
[junit4] 2> 58770 T285 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 58771 T285 oasc.Overseer.start Overseer (id=91746254737375236-127.0.0.1:52582_solr-n_0000000000) starting
[junit4] 2> 58772 T285 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4] 2> 58774 T285 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4] 2> 58778 T285 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-failure
[junit4] 2> 58781 T285 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-running
[junit4] 2> 58783 T285 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-completed
[junit4] 2> 58787 T285 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4] 2> 58790 T318 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 58791 T318 oasc.OverseerCollectionProcessor.prioritizeOverseerNodes prioritizing overseer nodes at 127.0.0.1:52582_solr
[junit4] 2> 58791 T317 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 58793 T317 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 58793 T317 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> 58793 T317 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1]
[junit4] 2> 58794 T317 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 58795 T316 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 58796 T308 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> 58796 T314 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> 59292 T285 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 59301 T285 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 59305 T316 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 59305 T285 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 59305 T317 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 59306 T308 oascc.ZkStateReader$3.process Updating live nodes... (0)
[junit4] 2> 59307 T314 oascc.ZkStateReader$3.process Updating live nodes... (0)
[junit4] 2> 59308 T285 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 59309 T316 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 59310 T320 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@16c92ab2 name:ZooKeeperConnection Watcher:127.0.0.1:52582/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 59310 T285 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 59311 T285 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 59312 T285 oascc.SolrZkClient.makePath makePath: /live_nodes/node1
[junit4] 2> 59314 T308 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 59314 T320 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 59315 T316 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 59315 T285 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 59316 T317 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> 59316 T317 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 59318 T316 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 59320 T285 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 59323 T316 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 59328 T316 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 59429 T320 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> 59429 T308 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> 59432 T285 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 59449 T320 oascc.ZkStateReader$3.process Updating live nodes... (0)
[junit4] 2> 59449 T308 oascc.ZkStateReader$3.process Updating live nodes... (0)
[junit4] 2> 59453 T285 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:52582 52582
[junit4] 2> 60933 T317 oasc.Overseer$ClusterStateUpdater.run WARN Solr cannot talk to ZK, exiting Overseer main queue loop org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /overseer/queue-work/qn-0000000002
[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.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.cloud.DistributedQueue.remove(DistributedQueue.java:179)
[junit4] 2> at org.apache.solr.cloud.DistributedQueue.poll(DistributedQueue.java:493)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.run(Overseer.java:267)
[junit4] 2> at java.lang.Thread.run(Thread.java:745)
[junit4] 2>
[junit4] 2> 64503 T317 oasc.Overseer$ClusterStateUpdater.run Overseer Loop exiting : 127.0.0.1:52582_solr
[junit4] 2> 64504 T302 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:52582 52582
[junit4] 2> 64505 T321 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> 64505 T285 oas.SolrTestCaseJ4.tearDown ###Ending testDoubleAssignment
[junit4] 2> 64509 T285 oas.SolrTestCaseJ4.setUp ###Starting testBadQueueItem
[junit4] 2> 64509 T285 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4] 1> client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 64510 T322 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4] 2> 64609 T285 oasc.ZkTestServer.run start zk server on port:57432
[junit4] 2> 64610 T285 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 64613 T328 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@624e9919 name:ZooKeeperConnection Watcher:127.0.0.1:57432 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 64614 T285 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 64616 T285 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 64618 T330 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@70ecc094 name:ZooKeeperConnection Watcher:127.0.0.1:57432 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 64618 T285 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 64618 T285 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 64622 T285 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 64625 T332 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1b0b725a name:ZooKeeperConnection Watcher:127.0.0.1:57432/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 64625 T285 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 64626 T285 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4] 2> 64630 T285 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 64632 T334 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@44c85733 name:ZooKeeperConnection Watcher:127.0.0.1:57432/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 64632 T285 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 64634 T285 oascc.SolrZkClient.makePath makePath: /overseer_elect
[junit4] 2> 64638 T285 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4] 2> 64641 T285 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:57432_solr
[junit4] 2> 64642 T285 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 64643 T285 oasc.Overseer.start Overseer (id=91746255122464771-127.0.0.1:57432_solr-n_0000000000) starting
[junit4] 2> 64644 T285 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4] 2> 64646 T285 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4] 2> 64648 T285 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-failure
[junit4] 2> 64650 T285 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-running
[junit4] 2> 64653 T285 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-completed
[junit4] 2> 64655 T285 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4] 2> 64658 T336 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 64659 T285 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4] 2> 64659 T336 oasc.OverseerCollectionProcessor.prioritizeOverseerNodes prioritizing overseer nodes at 127.0.0.1:57432_solr
[junit4] 2> 64659 T335 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 64660 T285 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4] 2> 64661 T285 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 64663 T285 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 64664 T338 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@52d888e2 name:ZooKeeperConnection Watcher:127.0.0.1:57432/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 64664 T285 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 64665 T285 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 64667 T285 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1
[junit4] 2> 64669 T338 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 64669 T332 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 64670 T334 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 64671 T335 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 64672 T335 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> 64673 T335 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1, shard2, shard3]
[junit4] 2> 64673 T335 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard2
[junit4] 2> 64675 T334 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 64676 T332 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> 64676 T338 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> 65171 T285 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard2/election
[junit4] 2> 65177 T285 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard2
[junit4] 2> 65182 T334 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 65183 T335 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 65183 T334 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 65185 T335 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> 65185 T335 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
[junit4] 2> 65185 T335 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard3
[junit4] 2> 65187 T334 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 65289 T332 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> 65289 T338 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> 65683 T285 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard3/election
[junit4] 2> 65690 T285 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard3
[junit4] 2> 65694 T334 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 65694 T334 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 65694 T334 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 65695 T335 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 65696 T334 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 65698 T335 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> 65698 T335 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
[junit4] 2> 65698 T335 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 65699 T334 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 65802 T332 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> 65802 T338 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> 66196 T285 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 66202 T285 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 66205 T334 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 66205 T334 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 66206 T334 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 66206 T335 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 66208 T334 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 66309 T332 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> 66309 T338 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> 66358 T334 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 66358 T334 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 66358 T334 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 66359 T334 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 66360 T335 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 66360 T335 oasc.Overseer$ClusterStateUpdater.checkKeyExistence ERROR Skipping invalid Overseer message because it has no collection specified: {
[junit4] 2> "operation":"state",
[junit4] 2> "state":"active",
[junit4] 2> "node_name":"127.0.0.1",
[junit4] 2> "core":"core0",
[junit4] 2> "core_node_name":"node0",
[junit4] 2> "collection":"",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://127.0.0.1/solr/"}
[junit4] 2> 66362 T335 oasc.Overseer$ClusterStateUpdater.checkKeyExistence ERROR Skipping invalid Overseer message because it has no collection specified: {
[junit4] 2> "operation":"deletecore",
[junit4] 2> "node_name":"127.0.0.1",
[junit4] 2> "core":"core0",
[junit4] 2> "core_node_name":"node0",
[junit4] 2> "collection":""}
[junit4] 2> 66364 T334 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 66364 T335 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"active",
[junit4] 2> "node_name":"127.0.0.1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"node1",
[junit4] 2> "collection":"collection2",
[junit4] 2> "numShards":"3",
[junit4] 2> "base_url":"http://127.0.0.1/solr/"}
[junit4] 2> 66365 T335 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection2 with shards [shard1, shard2, shard3]
[junit4] 2> 66365 T335 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard2
[junit4] 2> 66369 T334 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 66471 T332 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> 66471 T338 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> 66860 T285 oascc.SolrZkClient.makePath makePath: /collections/collection2/leader_elect/shard2/election
[junit4] 2> 66867 T285 oascc.SolrZkClient.makePath makePath: /collections/collection2/leaders/shard2
[junit4] 2> 66871 T334 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 66871 T334 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 66871 T334 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 66872 T335 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 66873 T334 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 66877 T335 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"active",
[junit4] 2> "node_name":"127.0.0.1",
[junit4] 2> "core":"core2",
[junit4] 2> "core_node_name":"node2",
[junit4] 2> "collection":"collection2",
[junit4] 2> "numShards":"3",
[junit4] 2> "base_url":"http://127.0.0.1/solr/"}
[junit4] 2> 66877 T335 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
[junit4] 2> 66877 T335 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard3
[junit4] 2> 66880 T334 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 66982 T332 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> 66982 T338 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> 67373 T285 oascc.SolrZkClient.makePath makePath: /collections/collection2/leader_elect/shard3/election
[junit4] 2> 67379 T285 oascc.SolrZkClient.makePath makePath: /collections/collection2/leaders/shard3
[junit4] 2> 67382 T334 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 67382 T334 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 67382 T334 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 67383 T334 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 67383 T335 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 67386 T335 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"active",
[junit4] 2> "node_name":"127.0.0.1",
[junit4] 2> "core":"core3",
[junit4] 2> "core_node_name":"node3",
[junit4] 2> "collection":"collection2",
[junit4] 2> "numShards":"3",
[junit4] 2> "base_url":"http://127.0.0.1/solr/"}
[junit4] 2> 67386 T335 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
[junit4] 2> 67386 T335 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 67388 T334 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 67489 T332 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> 67489 T338 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> 67884 T285 oascc.SolrZkClient.makePath makePath: /collections/collection2/leader_elect/shard1/election
[junit4] 2> 67894 T285 oascc.SolrZkClient.makePath makePath: /collections/collection2/leaders/shard1
[junit4] 2> 67900 T334 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 67900 T334 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 67901 T334 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 67902 T335 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 67906 T334 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 68008 T332 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> 68008 T338 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> 68053 T338 oascc.ZkStateReader$3.process Updating live nodes... (0)
[junit4] 2> 68054 T285 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:57432 57432
[junit4] 2> 68107 T322 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:57432 57432
[junit4] 2> 68108 T285 oas.SolrTestCaseJ4.tearDown ###Ending testBadQueueItem
[junit4] 2> 68109 T335 oasc.Overseer$ClusterStateUpdater.run Overseer Loop exiting : 127.0.0.1:57432_solr
[junit4] 2> 68110 T339 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> 68112 T285 oas.SolrTestCaseJ4.setUp ###Starting testStateChange
[junit4] 2> 68113 T285 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4] 1> client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 68113 T340 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4] 2> 68213 T285 oasc.ZkTestServer.run start zk server on port:47464
[junit4] 2> 68214 T285 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 68217 T346 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@600114c6 name:ZooKeeperConnection Watcher:127.0.0.1:47464/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 68217 T285 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 68218 T285 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 68219 T348 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1d4a9f46 name:ZooKeeperConnection Watcher:127.0.0.1:47464 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 68219 T285 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 68224 T285 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 68227 T350 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@5bbea9ba name:ZooKeeperConnection Watcher:127.0.0.1:47464 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 68227 T285 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 68227 T285 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 68230 T285 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4] 2> 68232 T285 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4] 2> 68234 T285 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4] 2> 68235 T285 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 68236 T285 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 68238 T352 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@4324f8fc name:ZooKeeperConnection Watcher:127.0.0.1:47464/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 68238 T285 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 68239 T285 oascc.SolrZkClient.makePath makePath: /overseer_elect
[junit4] 2> 68240 T285 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4] 2> 68242 T285 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:47464_solr
[junit4] 2> 68242 T285 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 68243 T285 oasc.Overseer.start Overseer (id=91746255358656515-127.0.0.1:47464_solr-n_0000000000) starting
[junit4] 2> 68244 T285 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4] 2> 68246 T285 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4] 2> 68248 T285 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-failure
[junit4] 2> 68249 T285 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-running
[junit4] 2> 68251 T285 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-completed
[junit4] 2> 68253 T285 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4] 2> 68259 T354 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 68260 T353 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 68260 T354 oasc.OverseerCollectionProcessor.prioritizeOverseerNodes prioritizing overseer nodes at 127.0.0.1:47464_solr
[junit4] 2> 68261 T285 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 68261 T353 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 68262 T353 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=null message={
[junit4] 2> "operation":"state",
[junit4] 2> "base_url":"http://127.0.0.1/solr",
[junit4] 2> "node_name":"node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "core":"core1",
[junit4] 2> "roles":"",
[junit4] 2> "state":"recovering"}
[junit4] 2> 68262 T353 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 68264 T352 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 68264 T346 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 0)
[junit4] 2> 68312 T285 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 68314 T352 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 68315 T353 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 68316 T353 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=null message={
[junit4] 2> "operation":"state",
[junit4] 2> "base_url":"http://127.0.0.1/solr",
[junit4] 2> "node_name":"node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "core":"core1",
[junit4] 2> "roles":"",
[junit4] 2> "state":"active"}
[junit4] 2> 68316 T353 oasc.Overseer$ClusterStateUpdater.updateState node=core_node1 is already registered
[junit4] 2> 68316 T353 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 68318 T352 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 68420 T346 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 0)
[junit4] 2> 68466 T285 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:47464 47464
[junit4] 2> 68789 T340 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:47464 47464
[junit4] 2> 68790 T285 oas.SolrTestCaseJ4.tearDown ###Ending testStateChange
[junit4] 2> 68791 T353 oasc.Overseer$ClusterStateUpdater.run Overseer Loop exiting : 127.0.0.1:47464_solr
[junit4] 2> 68791 T355 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> 68794 T285 oas.SolrTestCaseJ4.setUp ###Starting testShardLeaderChange
[junit4] 2> 68794 T285 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4] 1> client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 68794 T356 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4] 2> 68894 T285 oasc.ZkTestServer.run start zk server on port:38774
[junit4] 2> 68895 T285 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 68900 T362 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@621269ee name:ZooKeeperConnection Watcher:127.0.0.1:38774/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 68900 T285 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 68901 T285 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 68903 T364 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@4ccfef6f name:ZooKeeperConnection Watcher:127.0.0.1:38774 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 68904 T285 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 68908 T285 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 68911 T366 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@28481d12 name:ZooKeeperConnection Watcher:127.0.0.1:38774 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 68911 T285 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 68911 T285 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 68916 T285 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4] 2> 68921 T367 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 68921 T285 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 68924 T370 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@3fd24c59 name:ZooKeeperConnection Watcher:127.0.0.1:38774/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 68925 T367 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 68925 T371 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@5848cbc2 name:ZooKeeperConnection Watcher:127.0.0.1:38774/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 68926 T285 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 68927 T367 oascc.SolrZkClient.makePath makePath: /overseer_elect
[junit4] 2> 68927 T285 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4] 2> 68928 T367 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4] 2> 68932 T367 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:38774_solr
[junit4] 2> 68932 T367 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 68933 T285 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4] 2> 68933 T367 oasc.Overseer.start Overseer (id=91746255403286531-127.0.0.1:38774_solr-n_0000000000) starting
[junit4] 2> 68934 T285 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 68935 T367 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4] 2> 68936 T285 oascc.SolrZkClient.makePath makePath: /live_nodes/node1
[junit4] 2> 68937 T367 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4] 2> 68938 T371 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 68939 T367 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-failure
[junit4] 2> 68941 T367 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-running
[junit4] 2> 68949 T367 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-completed
[junit4] 2> 68952 T367 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4] 2> 68956 T367 oasc.OverseerTest$OverseerRestarter.run Killing overseer.
[junit4] 2> 68956 T373 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 68960 T367 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 68962 T375 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@3115a5d3 name:ZooKeeperConnection Watcher:127.0.0.1:38774/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 68962 T367 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 68963 T373 oasc.OverseerCollectionProcessor.amILeader According to ZK I (id=91746255403286531-127.0.0.1:38774_solr-n_0000000000) am no longer a leader.
[junit4] 2> 68963 T373 oasc.OverseerCollectionProcessor.prioritizeOverseerNodes prioritizing overseer nodes at 127.0.0.1:38774_solr
[junit4] 2> 68963 T373 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:745)
[junit4] 2>
[junit4] 2> 68965 T367 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:38774_solr
[junit4] 2> 68965 T367 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 68966 T367 oasc.Overseer.start Overseer (id=91746255403286533-127.0.0.1:38774_solr-n_0000000001) starting
[junit4] 2> 68971 T377 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 68971 T377 oasc.OverseerCollectionProcessor.prioritizeOverseerNodes prioritizing overseer nodes at 127.0.0.1:38774_solr
[junit4] 2> 68971 T376 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 68973 T376 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 68973 T376 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> 68973 T376 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1]
[junit4] 2> 68973 T376 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 68976 T375 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 68978 T371 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> 69439 T285 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 69451 T285 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 69455 T375 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 69456 T376 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 69457 T375 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 69457 T285 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 69460 T376 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> 69461 T376 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 69462 T285 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 69463 T375 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 69464 T379 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@29e4843c name:ZooKeeperConnection Watcher:127.0.0.1:38774/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 69464 T285 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 69464 T285 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 69465 T285 oascc.SolrZkClient.makePath makePath: /live_nodes/node2
[junit4] 2> 69468 T379 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 69468 T371 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 69470 T375 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 69470 T285 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 69471 T376 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> 69471 T376 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 69473 T375 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 69474 T285 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 69576 T371 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> 69576 T379 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> 69676 T285 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 69679 T375 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 69679 T375 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 69679 T375 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 69680 T376 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 69680 T376 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> 69680 T376 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=1
[junit4] 2> 69680 T376 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 69682 T375 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 69783 T379 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> 69783 T371 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> 70179 T285 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 70190 T371 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 70190 T379 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 70191 T285 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 70192 T379 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 70196 T375 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 70196 T375 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 70196 T375 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 70197 T376 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 70198 T375 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 70300 T379 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> 70393 T285 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 70394 T285 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 70396 T381 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1a63b2f8 name:ZooKeeperConnection Watcher:127.0.0.1:38774/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 70396 T285 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 70397 T285 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 70399 T285 oascc.SolrZkClient.makePath makePath: /live_nodes/node1
[junit4] 2> 70400 T379 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 70400 T381 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 70402 T375 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 70402 T285 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 70402 T375 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 70402 T375 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 70403 T376 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 70403 T376 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> 70404 T376 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 70406 T375 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 70407 T379 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 70407 T381 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 70408 T381 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 70408 T375 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 70408 T285 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 70409 T376 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> 70409 T376 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 70411 T375 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 70412 T285 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 70413 T383 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@72ab8c2b name:ZooKeeperConnection Watcher:127.0.0.1:38774/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 70413 T375 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 70413 T285 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 70414 T285 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 70415 T285 oascc.SolrZkClient.makePath makePath: /live_nodes/node2
[junit4] 2> 70417 T381 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 70417 T383 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 70419 T375 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 70419 T285 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 70419 T376 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> 70419 T376 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 70421 T375 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 70422 T285 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 70473 T367 oasc.OverseerTest$OverseerRestarter.run Killing overseer.
[junit4] 2> 70474 T367 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 70476 T385 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@352a2729 name:ZooKeeperConnection Watcher:127.0.0.1:38774/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 70476 T367 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 70476 T376 oasc.Overseer$ClusterStateUpdater.run Overseer Loop exiting : 127.0.0.1:38774_solr
[junit4] 2> 70477 T386 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> 70479 T367 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:38774_solr
[junit4] 2> 70479 T367 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 70480 T367 oasc.Overseer.start Overseer (id=91746255403286537-127.0.0.1:38774_solr-n_0000000002) starting
[junit4] 2> 70487 T388 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 70487 T388 oasc.OverseerCollectionProcessor.prioritizeOverseerNodes prioritizing overseer nodes at 127.0.0.1:38774_solr
[junit4] 2> 70488 T387 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 70489 T387 oasc.Overseer$ClusterStateUpdater.run Replaying operations from work queue.
[junit4] 2> 70489 T387 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> 70489 T387 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 70490 T383 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> 70491 T381 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> 70492 T387 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> 70493 T387 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 70493 T383 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> 70493 T381 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> 70495 T381 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> 70495 T383 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> 70497 T387 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> 70497 T387 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 70497 T381 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> 70497 T383 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> 70499 T387 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 70623 T285 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 70626 T385 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 70626 T285 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 70627 T387 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 70627 T387 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> 70627 T387 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 70629 T385 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 70630 T381 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 70630 T383 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 70630 T381 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> 70630 T383 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> 70631 T285 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 70632 T383 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 70635 T385 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 70635 T387 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 70639 T385 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 70740 T383 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> 70832 T285 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 70834 T285 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 70835 T390 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@6ca35f67 name:ZooKeeperConnection Watcher:127.0.0.1:38774/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 70836 T285 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 70837 T285 oascc.ZkS
[...truncated too long message...]
path:null path:null type:None
[junit4] 2> 87706 T285 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 87706 T285 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 87709 T285 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4] 2> 87710 T285 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4] 2> 87711 T285 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4] 2> 87712 T285 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 87713 T285 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 87714 T759 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@3a8ecaf2 name:ZooKeeperConnection Watcher:127.0.0.1:44494/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 87714 T285 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 87715 T285 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 87715 T285 oascc.SolrZkClient.makePath makePath: /live_nodes/node1
[junit4] 2> 87716 T759 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 87717 T753 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 87717 T285 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 87718 T761 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@31e5f219 name:ZooKeeperConnection Watcher:127.0.0.1:44494/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 87718 T285 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 87718 T285 oascc.SolrZkClient.makePath makePath: /overseer_elect
[junit4] 2> 87719 T285 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4] 2> 87721 T285 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:44494_solr
[junit4] 2> 87722 T285 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 87723 T285 oasc.Overseer.start Overseer (id=91746256635691012-127.0.0.1:44494_solr-n_0000000000) starting
[junit4] 2> 87724 T285 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4] 2> 87727 T285 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4] 2> 87729 T285 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-failure
[junit4] 2> 87730 T285 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-running
[junit4] 2> 87732 T285 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-completed
[junit4] 2> 87733 T285 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4] 2> 87736 T763 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 87737 T763 oasc.OverseerCollectionProcessor.prioritizeOverseerNodes prioritizing overseer nodes at 127.0.0.1:44494_solr
[junit4] 2> 87737 T762 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 87740 T761 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 87741 T762 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 87742 T762 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> 87742 T762 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1, shard2, shard3, shard4, shard5, shard6, shard7, shard8, shard9, shard10, shard11, shard12]
[junit4] 2> 87742 T762 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard2
[junit4] 2> 87745 T761 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 87745 T753 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> 87745 T759 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> 88241 T285 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard2/election
[junit4] 2> 88249 T285 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard2
[junit4] 2> 88252 T761 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 88252 T285 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 88252 T762 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 88254 T759 oascc.ZkStateReader$3.process Updating live nodes... (0)
[junit4] 2> 88254 T753 oascc.ZkStateReader$3.process Updating live nodes... (0)
[junit4] 2> 88255 T285 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:44494 44494
[junit4] 2> 88384 T747 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:44494 44494
[junit4] 2> 88386 T285 oas.SolrTestCaseJ4.tearDown ###Ending testPlaceholders
[junit4] 2> 88386 T762 oasc.Overseer$ClusterStateUpdater.run Overseer Loop exiting : 127.0.0.1:44494_solr
[junit4] 2> 88387 T764 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> 88389 T285 oas.SolrTestCaseJ4.initCore ####initCore
[junit4] 2> 88389 T285 oas.SolrTestCaseJ4.initCore ####initCore end
[junit4] 2> 91390 T285 oas.SolrTestCaseJ4.deleteCore ###deleteCore
[junit4] 2> NOTE: leaving temporary files on disk at: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux@2/solr/build/solr-core/test/J0/./solr.cloud.OverseerTest-BBD14D8DFBF4FAB-001
[junit4] 2> NOTE: test params are: codec=Lucene46: {}, docValues:{}, sim=RandomSimilarityProvider(queryNorm=false,coord=crazy): {}, locale=ca, timezone=Israel
[junit4] 2> NOTE: Linux 3.8.0-39-generic amd64/Oracle Corporation 1.8.0_20-ea (64-bit)/cpus=8,threads=1,free=58638320,total=189792256
[junit4] 2> NOTE: All tests run in this JVM: [URLClassifyProcessorTest, DistributedQueryElevationComponentTest, TestStandardQParsers, CopyFieldTest, MBeansHandlerTest, JsonLoaderTest, ScriptEngineTest, TestDocSet, AddSchemaFieldsUpdateProcessorFactoryTest, TestPHPSerializedResponseWriter, BasicFunctionalityTest, TestCloudManagedSchema, HdfsDirectoryTest, SOLR749Test, CoreAdminHandlerTest, LoggingHandlerTest, FieldMutatingUpdateProcessorTest, OverseerTest]
[junit4] Completed on J0 in 33.24s, 9 tests, 1 error <<< FAILURES!
[...truncated 1073 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: 390 suites, 1635 tests, 1 error, 37 ignored (16 assumptions)
Total time: 54 minutes 36 seconds
Build step 'Invoke Ant' marked build as failure
Description set: Java: 64bit/jdk1.8.0_20-ea-b11 -XX:+UseCompressedOops -XX:+UseConcMarkSweepGC
Archiving artifacts
Recording test results
Email was triggered for: Failure
Sending email for trigger: Failure