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/15 22:40:12 UTC
[JENKINS] Lucene-Solr-4.x-Linux (32bit/jdk1.8.0_20-ea-b11) - Build
# 10195 - Failure!
Build: http://jenkins.thetaphi.de/job/Lucene-Solr-4.x-Linux/10195/
Java: 32bit/jdk1.8.0_20-ea-b11 -client -XX:+UseParallelGC
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([1E0E4D6C4A9E0391:1A06C29F583BECB0]: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 11168 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-1E0E4D6C4A9E0391-001/init-core-data-001
[junit4] 2> 307783 T1635 oas.SolrTestCaseJ4.buildSSLConfig Randomized ssl (true) and clientAuth (false)
[junit4] 2> 307783 T1635 oas.SolrTestCaseJ4.initCore ####initCore
[junit4] 2> 307784 T1635 oas.SolrTestCaseJ4.initCore ####initCore end
[junit4] 2> 307786 T1635 oas.SolrTestCaseJ4.setUp ###Starting testBadQueueItem
[junit4] 2> 307787 T1635 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4] 1> client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 307787 T1636 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4] 2> 307887 T1635 oasc.ZkTestServer.run start zk server on port:45700
[junit4] 2> 307888 T1635 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 308038 T1642 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@632e46 name:ZooKeeperConnection Watcher:127.0.0.1:45700 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 308038 T1635 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 308041 T1635 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 308042 T1644 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@17ed22f name:ZooKeeperConnection Watcher:127.0.0.1:45700 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 308042 T1635 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 308042 T1635 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 308045 T1635 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 308047 T1646 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@c54f2d name:ZooKeeperConnection Watcher:127.0.0.1:45700/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 308047 T1635 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 308047 T1635 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4] 2> 308049 T1635 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 308050 T1648 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@3a4a2 name:ZooKeeperConnection Watcher:127.0.0.1:45700/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 308050 T1635 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 308051 T1635 oascc.SolrZkClient.makePath makePath: /overseer_elect
[junit4] 2> 308053 T1635 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4] 2> 308059 T1635 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:45700_solr
[junit4] 2> 308059 T1635 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 308061 T1635 oasc.Overseer.start Overseer (id=91762551800266755-127.0.0.1:45700_solr-n_0000000000) starting
[junit4] 2> 308062 T1635 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4] 2> 308065 T1635 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4] 2> 308067 T1635 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-failure
[junit4] 2> 308070 T1635 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-running
[junit4] 2> 308072 T1635 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-completed
[junit4] 2> 308075 T1635 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4] 2> 308078 T1650 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 308079 T1635 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4] 2> 308079 T1649 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 308080 T1635 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4] 2> 308081 T1635 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 308084 T1635 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 308085 T1652 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@149b3ba name:ZooKeeperConnection Watcher:127.0.0.1:45700/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 308085 T1635 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 308086 T1635 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 308088 T1635 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1
[junit4] 2> 308091 T1652 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 308091 T1646 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 308092 T1648 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 308093 T1649 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 308094 T1649 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> 308094 T1649 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1, shard2, shard3]
[junit4] 2> 308095 T1649 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard2
[junit4] 2> 308096 T1648 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 308097 T1646 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> 308097 T1652 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> 308593 T1635 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard2/election
[junit4] 2> 308606 T1635 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard2
[junit4] 2> 308615 T1648 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 308620 T1648 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 308620 T1649 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 308627 T1649 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> 308627 T1649 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
[junit4] 2> 308628 T1649 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard3
[junit4] 2> 308632 T1648 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 308735 T1652 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> 308735 T1646 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> 309120 T1635 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard3/election
[junit4] 2> 309131 T1635 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard3
[junit4] 2> 309137 T1648 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 309138 T1648 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 309138 T1648 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 309141 T1648 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 309142 T1649 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 309144 T1649 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> 309145 T1649 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
[junit4] 2> 309145 T1649 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 309149 T1648 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 309252 T1646 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> 309252 T1652 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> 309642 T1635 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 309652 T1635 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 309660 T1648 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 309661 T1648 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 309661 T1648 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 309663 T1649 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 309667 T1648 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 309770 T1646 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> 309770 T1652 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> 309814 T1648 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 309814 T1648 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 309814 T1648 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 309817 T1648 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 309817 T1649 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 309819 T1649 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> 309822 T1649 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> 309824 T1648 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 309824 T1649 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> 309825 T1649 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection2 with shards [shard1, shard2, shard3]
[junit4] 2> 309825 T1649 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard2
[junit4] 2> 309827 T1648 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 309932 T1646 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> 309932 T1652 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> 310321 T1635 oascc.SolrZkClient.makePath makePath: /collections/collection2/leader_elect/shard2/election
[junit4] 2> 310330 T1635 oascc.SolrZkClient.makePath makePath: /collections/collection2/leaders/shard2
[junit4] 2> 310339 T1648 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 310340 T1648 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 310340 T1648 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 310342 T1649 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 310347 T1648 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 310348 T1649 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> 310349 T1649 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
[junit4] 2> 310349 T1649 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard3
[junit4] 2> 310353 T1648 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 310456 T1646 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> 310456 T1652 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> 310847 T1635 oascc.SolrZkClient.makePath makePath: /collections/collection2/leader_elect/shard3/election
[junit4] 2> 310856 T1635 oascc.SolrZkClient.makePath makePath: /collections/collection2/leaders/shard3
[junit4] 2> 310866 T1648 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 310867 T1648 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 310867 T1648 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 311777 T1648 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 311777 T1649 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 311783 T1649 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> 311784 T1649 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
[junit4] 2> 311784 T1649 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 311787 T1648 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 311889 T1646 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> 311889 T1652 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> 312277 T1635 oascc.SolrZkClient.makePath makePath: /collections/collection2/leader_elect/shard1/election
[junit4] 2> 312282 T1635 oascc.SolrZkClient.makePath makePath: /collections/collection2/leaders/shard1
[junit4] 2> 312289 T1648 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 312289 T1648 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 312289 T1648 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 312290 T1649 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 312293 T1648 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 312395 T1652 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> 312395 T1646 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> 312441 T1652 oascc.ZkStateReader$3.process Updating live nodes... (0)
[junit4] 2> 312442 T1635 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:45700 45700
[junit4] 2> 313284 T1636 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:45700 45700
[junit4] 2> 313286 T1635 oas.SolrTestCaseJ4.tearDown ###Ending testBadQueueItem
[junit4] 2> 313287 T1649 oasc.Overseer$ClusterStateUpdater.run Overseer Loop exiting : 127.0.0.1:45700_solr
[junit4] 2> 313289 T1653 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> 313295 T1635 oas.SolrTestCaseJ4.setUp ###Starting testReplay
[junit4] 2> 313296 T1635 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4] 1> client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 313297 T1654 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4] 2> 313397 T1635 oasc.ZkTestServer.run start zk server on port:51163
[junit4] 2> 313397 T1635 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 313402 T1660 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@53e516 name:ZooKeeperConnection Watcher:127.0.0.1:51163/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 313403 T1635 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 313404 T1635 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 313406 T1662 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@bb7396 name:ZooKeeperConnection Watcher:127.0.0.1:51163 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 313406 T1635 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 313410 T1635 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 313411 T1664 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@142e697 name:ZooKeeperConnection Watcher:127.0.0.1:51163 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 313412 T1635 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 313412 T1635 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 313418 T1635 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4] 2> 313420 T1635 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4] 2> 313422 T1635 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4] 2> 313425 T1635 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 313430 T1635 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4] 2> 313438 T1635 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 313440 T1666 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1424da6 name:ZooKeeperConnection Watcher:127.0.0.1:51163/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 313441 T1635 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 313442 T1635 oascc.SolrZkClient.makePath makePath: /overseer_elect
[junit4] 2> 313446 T1635 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4] 2> 313452 T1635 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:51163_solr
[junit4] 2> 313453 T1635 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 313456 T1635 oasc.Overseer.start Overseer (id=91762552161632259-127.0.0.1:51163_solr-n_0000000000) starting
[junit4] 2> 313459 T1635 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4] 2> 313465 T1635 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-failure
[junit4] 2> 313471 T1635 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-running
[junit4] 2> 313477 T1635 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-completed
[junit4] 2> 313483 T1635 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4] 2> 313491 T1668 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 313493 T1667 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 313494 T1667 oasc.Overseer$ClusterStateUpdater.run Replaying operations from work queue.
[junit4] 2> 313495 T1667 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> 313497 T1660 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> 313502 T1667 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> 313503 T1660 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> 313506 T1667 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 313508 T1667 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 313509 T1667 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> 313513 T1666 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 313514 T1660 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> 313595 T1635 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:51163 51163
[junit4] 2> 314318 T1654 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:51163 51163
[junit4] 2> 314319 T1635 oas.SolrTestCaseJ4.tearDown ###Ending testReplay
[junit4] 2> 314320 T1667 oasc.Overseer$ClusterStateUpdater.run Overseer Loop exiting : 127.0.0.1:51163_solr
[junit4] 2> 314320 T1669 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> 314325 T1635 oas.SolrTestCaseJ4.setUp ###Starting testOverseerFailure
[junit4] 2> 314325 T1635 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4] 1> client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 314326 T1670 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4] 2> 314426 T1635 oasc.ZkTestServer.run start zk server on port:53555
[junit4] 2> 314427 T1635 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 314487 T1676 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@ca658d name:ZooKeeperConnection Watcher:127.0.0.1:53555 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 314487 T1635 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 314490 T1635 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 314492 T1678 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@10e99c1 name:ZooKeeperConnection Watcher:127.0.0.1:53555 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 314492 T1635 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 314492 T1635 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 314495 T1635 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 314497 T1680 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@188b569 name:ZooKeeperConnection Watcher:127.0.0.1:53555/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 314497 T1635 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 314498 T1635 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4] 2> 314500 T1635 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4] 2> 314502 T1635 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4] 2> 314503 T1635 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 314505 T1635 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 314506 T1682 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@86fdc3 name:ZooKeeperConnection Watcher:127.0.0.1:53555/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 314506 T1635 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 314507 T1635 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 314508 T1635 oascc.SolrZkClient.makePath makePath: /live_nodes/node1
[junit4] 2> 314510 T1680 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 314510 T1682 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 314510 T1635 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 314511 T1684 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1f30813 name:ZooKeeperConnection Watcher:127.0.0.1:53555/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 314511 T1635 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 314512 T1635 oascc.SolrZkClient.makePath makePath: /overseer_elect
[junit4] 2> 314513 T1635 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4] 2> 314515 T1635 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:53555_solr
[junit4] 2> 314516 T1635 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 314517 T1635 oasc.Overseer.start Overseer (id=91762552228806660-127.0.0.1:53555_solr-n_0000000000) starting
[junit4] 2> 314518 T1635 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4] 2> 314520 T1635 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4] 2> 314522 T1635 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-failure
[junit4] 2> 314525 T1635 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-running
[junit4] 2> 314530 T1635 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-completed
[junit4] 2> 314535 T1635 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4] 2> 314541 T1686 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 314542 T1685 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 315544 T1684 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 315545 T1685 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 315546 T1685 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> 315546 T1685 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1]
[junit4] 2> 315546 T1685 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 315548 T1684 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 315549 T1680 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> 315549 T1682 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> 316044 T1635 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 316051 T1635 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 316055 T1684 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 316055 T1635 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 316056 T1685 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 316059 T1635 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 316059 T1684 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 316061 T1685 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"active",
[junit4] 2> "node_name":"node1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"core_node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node1/solr/"}
[junit4] 2> 316062 T1685 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 316064 T1684 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 316166 T1680 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> 316166 T1682 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> 317219 T1635 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 317224 T1635 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 317226 T1688 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@64557d name:ZooKeeperConnection Watcher:127.0.0.1:53555/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 317226 T1635 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 317227 T1685 oasc.Overseer$ClusterStateUpdater.run Overseer Loop exiting : 127.0.0.1:53555_solr
[junit4] 2> 317228 T1689 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> 317229 T1635 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:53555_solr
[junit4] 2> 317230 T1635 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 317232 T1635 oasc.Overseer.start Overseer (id=91762552228806661-127.0.0.1:53555_solr-n_0000000001) starting
[junit4] 2> 317241 T1691 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 317241 T1690 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 317243 T1690 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 317244 T1690 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> 317244 T1690 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 317246 T1688 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 317247 T1680 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> 317247 T1682 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> 317250 T1688 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 317250 T1635 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 317251 T1690 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 317255 T1682 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 317259 T1635 oasc.LeaderElector.checkIfIamLeader WARN Failed setting watch org.apache.zookeeper.KeeperException$NoNodeException: KeeperErrorCode = NoNode for /collections/collection1/leader_elect/shard1/election/91762552228806659-node1_core1-n_0000000002
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:111)
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] 2> at org.apache.zookeeper.ZooKeeper.getData(ZooKeeper.java:1155)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:277)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:274)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.getData(SolrZkClient.java:274)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:127)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.joinElection(LeaderElector.java:267)
[junit4] 2> at org.apache.solr.cloud.OverseerTest$MockZKController.publishState(OverseerTest.java:155)
[junit4] 2> at org.apache.solr.cloud.OverseerTest.testOverseerFailure(OverseerTest.java:661)
[junit4] 2> at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
[junit4] 2> at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
[junit4] 2> at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
[junit4] 2> at java.lang.reflect.Method.invoke(Method.java:483)
[junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1618)
[junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:827)
[junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:863)
[junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:877)
[junit4] 2> at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
[junit4] 2> at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:50)
[junit4] 2> at org.apache.lucene.util.TestRuleFieldCacheSanity$1.evaluate(TestRuleFieldCacheSanity.java:51)
[junit4] 2> at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
[junit4] 2> at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
[junit4] 2> at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:49)
[junit4] 2> at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:65)
[junit4] 2> at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
[junit4] 2> at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
[junit4] 2> at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:360)
[junit4] 2> at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:793)
[junit4] 2> at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:453)
[junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:836)
[junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:738)
[junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:772)
[junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:783)
[junit4] 2> at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
[junit4] 2> at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
[junit4] 2> at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
[junit4] 2> at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:42)
[junit4] 2> at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
[junit4] 2> at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
[junit4] 2> at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
[junit4] 2> at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
[junit4] 2> at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
[junit4] 2> at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
[junit4] 2> at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:43)
[junit4] 2> at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
[junit4] 2> at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:65)
[junit4] 2> at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:55)
[junit4] 2> at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
[junit4] 2> at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:360)
[junit4] 2> at java.lang.Thread.run(Thread.java:745)
[junit4] 2>
[junit4] 2> 317261 T1688 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 317262 T1682 oasc.LeaderElector$ElectionWatcher.process WARN org.apache.zookeeper.KeeperException$NoNodeException: KeeperErrorCode = NoNode for /collections/collection1/leader_elect/shard1/election
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:111)
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] 2> at org.apache.zookeeper.ZooKeeper.getChildren(ZooKeeper.java:1472)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:260)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:257)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.getChildren(SolrZkClient.java:257)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:94)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.access$200(LeaderElector.java:55)
[junit4] 2> at org.apache.solr.cloud.LeaderElector$ElectionWatcher.process(LeaderElector.java:303)
[junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:522)
[junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:498)
[junit4] 2>
[junit4] 2> 317263 T1690 oasc.SolrException.log ERROR Problem cleaning up collection in zk:collection1:org.apache.zookeeper.KeeperException$NotEmptyException: KeeperErrorCode = Directory not empty for /collections/collection1
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:125)
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] 2> at org.apache.zookeeper.ZooKeeper.delete(ZooKeeper.java:873)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$2.execute(SolrZkClient.java:177)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$2.execute(SolrZkClient.java:174)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.delete(SolrZkClient.java:174)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.clean(SolrZkClient.java:631)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.removeCore(Overseer.java:1069)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.processMessage(Overseer.java:342)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.run(Overseer.java:241)
[junit4] 2> at java.lang.Thread.run(Thread.java:745)
[junit4] 2>
[junit4] 2> 317263 T1680 oascc.ZkStateReader$3.process Updating live nodes... (0)
[junit4] 2> 317263 T1682 oascc.ZkStateReader$3.process Updating live nodes... (0)
[junit4] 2> 317268 T1635 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:53555 53555
[junit4] 2> 317997 T1670 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:53555 53555
[junit4] 2> 317998 T1635 oas.SolrTestCaseJ4.tearDown ###Ending testOverseerFailure
[junit4] 2> 317999 T1690 oasc.Overseer$ClusterStateUpdater.run Overseer Loop exiting : 127.0.0.1:53555_solr
[junit4] 2> 318000 T1692 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> NOTE: reproduce with: ant test -Dtestcase=OverseerTest -Dtests.method=testOverseerFailure -Dtests.seed=1E0E4D6C4A9E0391 -Dtests.multiplier=3 -Dtests.slow=true -Dtests.locale=de -Dtests.timezone=Asia/Ujung_Pandang -Dtests.file.encoding=ISO-8859-1
[junit4] ERROR 3.71s J0 | OverseerTest.testOverseerFailure <<<
[junit4] > Throwable #1: org.apache.zookeeper.KeeperException$NoNodeException: KeeperErrorCode = NoNode for /collections/collection1/leader_elect/shard1/election
[junit4] > at __randomizedtesting.SeedInfo.seed([1E0E4D6C4A9E0391:1A06C29F583BECB0]:0)
[junit4] > at org.apache.zookeeper.KeeperException.create(KeeperException.java:111)
[junit4] > at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] > at org.apache.zookeeper.ZooKeeper.getChildren(ZooKeeper.java:1472)
[junit4] > at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:260)
[junit4] > at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:257)
[junit4] > at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
[junit4] > at org.apache.solr.common.cloud.SolrZkClient.getChildren(SolrZkClient.java:257)
[junit4] > at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:94)
[junit4] > at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:134)
[junit4] > at org.apache.solr.cloud.LeaderElector.joinElection(LeaderElector.java:267)
[junit4] > at org.apache.solr.cloud.OverseerTest$MockZKController.publishState(OverseerTest.java:155)
[junit4] > at org.apache.solr.cloud.OverseerTest.testOverseerFailure(OverseerTest.java:661)
[junit4] > at java.lang.Thread.run(Thread.java:745)
[junit4] 2> 318034 T1635 oas.SolrTestCaseJ4.setUp ###Starting testShardAssignment
[junit4] 2> 318035 T1635 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4] 1> client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 318036 T1693 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4] 2> 318135 T1635 oasc.ZkTestServer.run start zk server on port:55650
[junit4] 2> 318136 T1635 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 318177 T1699 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@cf998 name:ZooKeeperConnection Watcher:127.0.0.1:55650 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 318178 T1635 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 318179 T1635 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 318180 T1701 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1380fec name:ZooKeeperConnection Watcher:127.0.0.1:55650 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 318181 T1635 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 318181 T1635 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 318184 T1635 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 318185 T1703 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@b1fd65 name:ZooKeeperConnection Watcher:127.0.0.1:55650/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 318185 T1635 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 318186 T1635 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4] 2> 318189 T1635 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 318190 T1705 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1900ec1 name:ZooKeeperConnection Watcher:127.0.0.1:55650/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 318191 T1635 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 318191 T1635 oascc.SolrZkClient.makePath makePath: /overseer_elect
[junit4] 2> 318193 T1635 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4] 2> 318196 T1635 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:55650_solr
[junit4] 2> 318196 T1635 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 318198 T1635 oasc.Overseer.start Overseer (id=91762552471879683-127.0.0.1:55650_solr-n_0000000000) starting
[junit4] 2> 318199 T1635 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4] 2> 318201 T1635 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4] 2> 318203 T1635 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-failure
[junit4] 2> 318207 T1635 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-running
[junit4] 2> 318210 T1635 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-completed
[junit4] 2> 318212 T1635 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4] 2> 318215 T1707 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 318216 T1706 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 318218 T1635 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4] 2> 318224 T1635 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4] 2> 318226 T1635 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 318228 T1635 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 318229 T1709 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@4dff12 name:ZooKeeperConnection Watcher:127.0.0.1:55650/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 318229 T1635 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 318230 T1635 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 318231 T1635 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1
[junit4] 2> 318233 T1703 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 318233 T1709 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 318235 T1705 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 318236 T1706 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 318236 T1706 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> 318236 T1706 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1, shard2, shard3]
[junit4] 2> 318237 T1706 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard2
[junit4] 2> 318238 T1705 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 318239 T1703 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> 318239 T1709 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> 318735 T1635 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard2/election
[junit4] 2> 318741 T1635 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard2
[junit4] 2> 318746 T1705 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 318748 T1706 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 318748 T1705 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 318751 T1706 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> 318751 T1706 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
[junit4] 2> 318751 T1706 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard3
[junit4] 2> 318753 T1705 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 318855 T1703 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> 318855 T1709 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> 319248 T1635 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard3/election
[junit4] 2> 319351 T1635 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard3
[junit4] 2> 319354 T1705 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 319354 T1705 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 319354 T1705 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 319355 T1705 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 319355 T1706 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 319358 T1706 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> 319358 T1706 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
[junit4] 2> 319359 T1706 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 319361 T1705 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 319463 T1703 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> 319463 T1709 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> 319855 T1635 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 319864 T1635 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 319871 T1705 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 319872 T1705 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 319872 T1705 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 319874 T1705 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 319874 T1706 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 319881 T1706 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"active",
[junit4] 2> "node_name":"127.0.0.1",
[junit4] 2> "core":"core4",
[junit4] 2> "core_node_name":"node4",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"3",
[junit4] 2> "base_url":"http://127.0.0.1/solr/"}
[junit4] 2> 319882 T1706 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
[junit4] 2> 319882 T1706 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard2
[junit4] 2> 319886 T1705 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 319988 T1703 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> 319988 T1709 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> 320374 T1635 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard2/election
[junit4] 2> 320380 T1705 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 320380 T1705 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 320380 T1705 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 320381 T1706 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 320382 T1706 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"active",
[junit4] 2> "node_name":"127.0.0.1",
[junit4] 2> "core":"core5",
[junit4] 2> "core_node_name":"node5",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"3",
[junit4] 2> "base_url":"http://127.0.0.1/solr/"}
[junit4] 2> 320382 T1706 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
[junit4] 2> 320383 T1706 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard3
[junit4] 2> 320384 T1705 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 320488 T1709 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> 320488 T1703 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> 320880 T1635 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard3/election
[junit4] 2> 320887 T1705 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 320887 T1705 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 320887 T1705 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 320888 T1706 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 320889 T1706 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"active",
[junit4] 2> "node_name":"127.0.0.1",
[junit4] 2> "core":"core6",
[junit4] 2> "core_node_name":"node6",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"3",
[junit4] 2> "base_url":"http://127.0.0.1/solr/"}
[junit4] 2> 320889 T1706 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
[junit4] 2> 320889 T1706 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 320891 T1705 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 321057 T1709 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> 321057 T1703 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> 321387 T1635 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 321392 T1709 oascc.ZkStateReader$3.process Updating live nodes... (0)
[junit4] 2> 321394 T1635 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:55650 55650
[junit4] 2> 322088 T1693 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:55650 55650
[junit4] 2> 322089 T1635 oas.SolrTestCaseJ4.tearDown ###Ending testShardAssignment
[junit4] 2> 322089 T1706 oasc.Overseer$ClusterStateUpdater.run Overseer Loop exiting : 127.0.0.1:55650_solr
[junit4] 2> 322090 T1710 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> 322094 T1635 oas.SolrTestCaseJ4.setUp ###Starting testPlaceholders
[junit4] 2> 322095 T1635 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4] 1> client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 322096 T1711 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4] 2> 322196 T1635 oasc.ZkTestServer.run start zk server on port:33533
[junit4] 2> 322196 T1635 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 322200 T1717 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@dc4d1c name:ZooKeeperConnection Watcher:127.0.0.1:33533/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 322200 T1635 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 322201 T1635 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 322202 T1719 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1f9b780 name:ZooKeeperConnection Watcher:127.0.0.1:33533 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 322202 T1635 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 322204 T1635 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 322206 T1721 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@7d6fc2 name:ZooKeeperConnection Watcher:127.0.0.1:33533 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 322206 T1635 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 322206 T1635 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 322209 T1635 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4] 2> 322210 T1635 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4] 2> 322212 T1635 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4] 2> 322213 T1635 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 322215 T1635 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 322216 T1723 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1d53689 name:ZooKeeperConnection Watcher:127.0.0.1:33533/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 322216 T1635 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 322217 T1635 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 322219 T1635 oascc.SolrZkClient.makePath makePath: /live_nodes/node1
[junit4] 2> 322221 T1717 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 322222 T1723 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 322222 T1635 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 322223 T1725 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1513602 name:ZooKeeperConnection Watcher:127.0.0.1:33533/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 322224 T1635 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 322224 T1635 oascc.SolrZkClient.makePath makePath: /overseer_elect
[junit4] 2> 322226 T1635 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4] 2> 322229 T1635 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:33533_solr
[junit4] 2> 322229 T1635 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 322231 T1635 oasc.Overseer.start Overseer (id=91762552738021380-127.0.0.1:33533_solr-n_0000000000) starting
[junit4] 2> 322232 T1635 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4] 2> 322234 T1635 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4] 2> 322237 T1635 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-failure
[junit4] 2> 322241 T1635 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-running
[junit4] 2> 322243 T1635 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-completed
[junit4] 2> 322246 T1635 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4] 2> 322249 T1727 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 322250 T1726 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 322251 T1726 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 322252 T1726 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> 322252 T1726 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1, shard2, shard3, shard4, shard5, shard6, shard7, shard8, shard9, shard10, shard11, shard12]
[junit4] 2> 322252 T1726 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard2
[junit4] 2> 322254 T1725 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 322255 T1717 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> 322255 T1723 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> 322751 T1635 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard2/election
[junit4] 2> 322758 T1635 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard2
[junit4] 2> 322762 T1725 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 322763 T1635 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 322764 T1726 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 322765 T1712 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x146018e37a20004, likely client has closed socket
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:228)
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208)
[junit4] 2> at java.lang.Thread.run(Thread.java:745)
[junit4] 2>
[junit4] 2> 322766 T1717 oascc.ZkStateReader$3.process Updating live nodes... (0)
[junit4] 2> 322766 T1723 oascc.ZkStateReader$3.process Updating live nodes... (0)
[junit4] 2> 322768 T1635 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:33533 33533
[junit4] 2> 322893 T1709 oasc.LeaderElector$ElectionWatcher.process WARN org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /collections/collection1/leader_elect/shard1/election
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:12
[...truncated too long message...]
unit4] 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> 338379 T2198 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1]
[junit4] 2> 338380 T2198 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 338384 T2197 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 338385 T2195 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> 338385 T2189 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> 338876 T1635 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 338884 T1635 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 338890 T2197 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 338890 T1635 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 338891 T2198 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 338892 T2189 oascc.ZkStateReader$3.process Updating live nodes... (0)
[junit4] 2> 338892 T2195 oascc.ZkStateReader$3.process Updating live nodes... (0)
[junit4] 2> 338893 T1635 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 338894 T2197 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 338895 T2201 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1951c04 name:ZooKeeperConnection Watcher:127.0.0.1:59779/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 338895 T1635 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 338896 T1635 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 338897 T1635 oascc.SolrZkClient.makePath makePath: /live_nodes/node1
[junit4] 2> 338899 T2189 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 338899 T2201 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 338900 T2197 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 338900 T1635 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 338901 T2198 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> 338902 T2198 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 338903 T2197 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 338905 T1635 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 338908 T2197 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 338911 T2197 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 339013 T2189 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> 339013 T2201 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> 339014 T1635 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 339016 T2189 oascc.ZkStateReader$3.process Updating live nodes... (0)
[junit4] 2> 339016 T2201 oascc.ZkStateReader$3.process Updating live nodes... (0)
[junit4] 2> 339017 T1635 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:59779 59779
[junit4] 2> 339838 T2183 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:59779 59779
[junit4] 2> 339841 T1635 oas.SolrTestCaseJ4.tearDown ###Ending testDoubleAssignment
[junit4] 2> 339842 T2198 oasc.Overseer$ClusterStateUpdater.run Overseer Loop exiting : 127.0.0.1:59779_solr
[junit4] 2> 339843 T2202 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> 339846 T1635 oas.SolrTestCaseJ4.initCore ####initCore
[junit4] 2> 339846 T1635 oas.SolrTestCaseJ4.initCore ####initCore end
[junit4] 2> 342847 T1635 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-1E0E4D6C4A9E0391-001
[junit4] 2> NOTE: test params are: codec=Lucene46: {}, docValues:{}, sim=RandomSimilarityProvider(queryNorm=true,coord=no): {}, locale=de, timezone=Asia/Ujung_Pandang
[junit4] 2> NOTE: Linux 3.8.0-39-generic i386/Oracle Corporation 1.8.0_20-ea (32-bit)/cpus=8,threads=1,free=107569280,total=241696768
[junit4] 2> NOTE: All tests run in this JVM: [SystemInfoHandlerTest, ReturnFieldsTest, SolrIndexSplitterTest, SpatialFilterTest, TestFreeTextSuggestions, TestSimpleQParserPlugin, AddSchemaFieldsUpdateProcessorFactoryTest, TestNonDefinedSimilarityFactory, CircularListTest, DistributedSpellCheckComponentTest, ResponseHeaderTest, TestTrie, AssignTest, TestLRUCache, TestLMJelinekMercerSimilarityFactory, TestJoin, TestMergePolicyConfig, TestSchemaVersionResource, TestFieldSortValues, TriLevelCompositeIdRoutingTest, MoreLikeThisHandlerTest, SolrInfoMBeanTest, QueryParsingTest, TestJmxMonitoredMap, LukeRequestHandlerTest, TestRestManager, TermVectorComponentTest, TestSolrQueryParserResource, SyncSliceTest, TestWriterPerf, TestValueSourceCache, TestManagedResource, BadComponentTest, MergeStrategyTest, TestStressUserVersions, SpellPossibilityIteratorTest, DocExpirationUpdateProcessorFactoryTest, TestRandomDVFaceting, TestShardHandlerFactory, CursorPagingTest, ZkCLITest, CoreAdminCreateDiscoverTest, CacheHeaderTest, OverseerTest]
[junit4] Completed on J0 in 35.11s, 9 tests, 1 error <<< FAILURES!
[...truncated 856 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: 393 suites, 1637 tests, 1 error, 37 ignored (16 assumptions)
Total time: 56 minutes 41 seconds
Build step 'Invoke Ant' marked build as failure
Description set: Java: 32bit/jdk1.8.0_20-ea-b11 -client -XX:+UseParallelGC
Archiving artifacts
Recording test results
Email was triggered for: Failure
Sending email for trigger: Failure