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/01/03 10:20:41 UTC
[JENKINS] Lucene-Solr-4.x-Linux (64bit/jdk1.6.0_45) - Build # 8839
- Failure!
Build: http://jenkins.thetaphi.de/job/Lucene-Solr-4.x-Linux/8839/
Java: 64bit/jdk1.6.0_45 -XX:+UseCompressedOops -XX:+UseSerialGC
1 tests failed.
REGRESSION: org.apache.solr.cloud.OverseerTest.testOverseerFailure
Error Message:
KeeperErrorCode = NodeExists for /collections/collection1/leaders/shard1
Stack Trace:
org.apache.zookeeper.KeeperException$NodeExistsException: KeeperErrorCode = NodeExists for /collections/collection1/leaders/shard1
at __randomizedtesting.SeedInfo.seed([DC4888080066F44D:D84007FB12C31B6C]:0)
at org.apache.zookeeper.KeeperException.create(KeeperException.java:119)
at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
at org.apache.zookeeper.ZooKeeper.create(ZooKeeper.java:783)
at org.apache.solr.common.cloud.SolrZkClient$10.execute(SolrZkClient.java:428)
at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:425)
at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:382)
at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:369)
at org.apache.solr.cloud.ShardLeaderElectionContextBase.runLeaderProcess(ElectionContext.java:112)
at org.apache.solr.cloud.LeaderElector.runIamLeaderProcess(LeaderElector.java:165)
at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:109)
at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:157)
at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:157)
at org.apache.solr.cloud.LeaderElector.joinElection(LeaderElector.java:277)
at org.apache.solr.cloud.OverseerTest$MockZKController.publishState(OverseerTest.java:153)
at org.apache.solr.cloud.OverseerTest.testOverseerFailure(OverseerTest.java:584)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
at java.lang.reflect.Method.invoke(Method.java:597)
at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1559)
at com.carrotsearch.randomizedtesting.RandomizedRunner.access$600(RandomizedRunner.java:79)
at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:737)
at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:773)
at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:787)
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:70)
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:358)
at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:782)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:442)
at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:746)
at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:648)
at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:682)
at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:693)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:42)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:43)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
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:358)
at java.lang.Thread.run(Thread.java:662)
Build Log:
[...truncated 9856 lines...]
[junit4] Suite: org.apache.solr.cloud.OverseerTest
[junit4] 2> 707096 T2953 oas.SolrTestCaseJ4.initCore ####initCore
[junit4] 2> Creating dataDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./solrtest-OverseerTest-1388740279768
[junit4] 2> 707097 T2953 oas.SolrTestCaseJ4.initCore ####initCore end
[junit4] 2> 707100 T2953 oas.SolrTestCaseJ4.setUp ###Starting testShardAssignment
[junit4] 2> 707100 T2953 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4] 2> 707100 T2954 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4] 2> 707200 T2953 oasc.ZkTestServer.run start zk server on port:48100
[junit4] 2> 707202 T2953 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 707342 T2961 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@25e7506f name:ZooKeeperConnection Watcher:127.0.0.1:48100 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 707342 T2953 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 707348 T2953 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 707350 T2964 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@3898eae7 name:ZooKeeperConnection Watcher:127.0.0.1:48100 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 707351 T2953 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 707352 T2953 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 707360 T2953 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 707362 T2967 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@5f177e29 name:ZooKeeperConnection Watcher:127.0.0.1:48100/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 707362 T2953 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 707363 T2953 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4] 2> 707368 T2953 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 707371 T2970 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@322f46eb name:ZooKeeperConnection Watcher:127.0.0.1:48100/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 707371 T2953 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 707373 T2953 oascc.SolrZkClient.makePath makePath: /overseer_elect
[junit4] 2> 707379 T2953 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4] 2> 707390 T2953 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 707396 T2953 oasc.Overseer.start Overseer (id=91012482975268867-127.0.0.1:48100_solr-n_0000000000) starting
[junit4] 2> 707401 T2953 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4] 2> 707410 T2953 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4] 2> 707419 T2953 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4] 2> 707426 T2972 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 707428 T2953 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4] 2> 707431 T2971 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 707438 T2953 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4] 2> 707443 T2953 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 707451 T2953 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 707453 T2975 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@76b02347 name:ZooKeeperConnection Watcher:127.0.0.1:48100/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 707454 T2953 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 707457 T2953 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 707465 T2953 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1
[junit4] 2> 707472 T2967 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 707473 T2975 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 707479 T2970 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 707482 T2971 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 707484 T2971 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> 707484 T2971 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1, shard2, shard3]
[junit4] 2> 707485 T2971 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 707490 T2970 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 707492 T2975 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> 707493 T2967 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> 707979 T2953 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 708002 T2953 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 708018 T2970 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 708024 T2971 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 708024 T2970 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 708034 T2971 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> 708035 T2971 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
[junit4] 2> 708035 T2971 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard2
[junit4] 2> 708041 T2970 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 708146 T2975 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> 708147 T2967 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> 708525 T2953 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard2/election
[junit4] 2> 708542 T2953 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard2
[junit4] 2> 708555 T2970 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 708556 T2970 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 708556 T2970 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 708562 T2970 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 708563 T2971 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 708573 T2971 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> 708573 T2971 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
[junit4] 2> 708574 T2971 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard3
[junit4] 2> 708580 T2970 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 708685 T2967 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> 708685 T2975 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> 709063 T2953 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard3/election
[junit4] 2> 709082 T2953 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard3
[junit4] 2> 709094 T2970 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 709094 T2970 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 709095 T2970 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 709101 T2970 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 709102 T2971 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 709114 T2971 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> 709115 T2971 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
[junit4] 2> 709115 T2971 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 709122 T2970 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 709227 T2975 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> 709227 T2967 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> 709602 T2953 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 709623 T2970 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 709623 T2970 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 709623 T2970 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 709627 T2971 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 709629 T2971 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> 709629 T2971 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
[junit4] 2> 709630 T2971 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard2
[junit4] 2> 709636 T2970 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 709742 T2975 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> 709742 T2967 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> 710123 T2953 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard2/election
[junit4] 2> 710142 T2970 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 710143 T2970 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 710143 T2970 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 710148 T2971 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 710149 T2971 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> 710150 T2971 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
[junit4] 2> 710150 T2971 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard3
[junit4] 2> 710156 T2970 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 710262 T2975 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> 710262 T2967 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> 710643 T2953 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard3/election
[junit4] 2> 710664 T2975 oascc.ZkStateReader$3.process Updating live nodes... (0)
[junit4] 2> 710670 T2953 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:48100 48100
[junit4] 2> 710765 T2953 oas.SolrTestCaseJ4.tearDown ###Ending testShardAssignment
[junit4] 1> client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 710773 T2953 oas.SolrTestCaseJ4.setUp ###Starting testReplay
[junit4] 2> 710773 T2953 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4] 2> 710773 T2976 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4] 2> 710873 T2953 oasc.ZkTestServer.run start zk server on port:55555
[junit4] 2> 710875 T2953 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 710879 T2983 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1061dc40 name:ZooKeeperConnection Watcher:127.0.0.1:55555/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 710880 T2953 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 710882 T2953 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 710884 T2986 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@179f7d57 name:ZooKeeperConnection Watcher:127.0.0.1:55555 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 710884 T2953 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 710947 T2953 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 710949 T2989 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@67a4feda name:ZooKeeperConnection Watcher:127.0.0.1:55555 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 710950 T2953 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 710950 T2953 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 710956 T2953 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4] 2> 710962 T2953 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4] 2> 710968 T2953 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4] 2> 710972 T2953 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 710982 T2953 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4] 2> 710993 T2953 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 710995 T2992 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@7778b32a name:ZooKeeperConnection Watcher:127.0.0.1:55555/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 710995 T2953 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 710997 T2953 oascc.SolrZkClient.makePath makePath: /overseer_elect
[junit4] 2> 711003 T2953 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4] 2> 711013 T2953 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 711019 T2953 oasc.Overseer.start Overseer (id=91012483216441347-127.0.0.1:55555_solr-n_0000000000) starting
[junit4] 2> 711024 T2953 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4] 2> 711036 T2953 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4] 2> 711043 T2994 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 711053 T2993 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 711054 T2993 oasc.Overseer$ClusterStateUpdater.run Replaying operations from work queue.
[junit4] 2> 711056 T2993 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> 711058 T2983 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> 711067 T2993 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> 711070 T2983 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> 711078 T2993 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 711084 T2993 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 711085 T2993 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> 711092 T2992 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 711094 T2983 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> 711157 T2953 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:55555 55555
[junit4] 2> 711260 T2953 oas.SolrTestCaseJ4.tearDown ###Ending testReplay
[junit4] 1> client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 711269 T2953 oas.SolrTestCaseJ4.setUp ###Starting testPlaceholders
[junit4] 2> 711269 T2953 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4] 2> 711270 T2995 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4] 2> 711370 T2953 oasc.ZkTestServer.run start zk server on port:43728
[junit4] 2> 711372 T2953 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 711376 T3002 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@acac8ca name:ZooKeeperConnection Watcher:127.0.0.1:43728/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 711377 T2953 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 711378 T2953 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 711381 T3005 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@475dc9a5 name:ZooKeeperConnection Watcher:127.0.0.1:43728 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 711382 T2953 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 711418 T2953 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 711422 T3008 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1c09c8d name:ZooKeeperConnection Watcher:127.0.0.1:43728 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 711422 T2953 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 711423 T2953 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 711429 T2953 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4] 2> 711435 T2953 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4] 2> 711441 T2953 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4] 2> 711447 T2953 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 711455 T2953 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 711457 T3011 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@43054ef3 name:ZooKeeperConnection Watcher:127.0.0.1:43728/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 711457 T2953 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 711460 T2953 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 711468 T2953 oascc.SolrZkClient.makePath makePath: /live_nodes/node1
[junit4] 2> 711475 T3002 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 711476 T3011 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 711478 T2953 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 711480 T3014 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@520ebd99 name:ZooKeeperConnection Watcher:127.0.0.1:43728/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 711481 T2953 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 711482 T2953 oascc.SolrZkClient.makePath makePath: /overseer_elect
[junit4] 2> 711489 T2953 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4] 2> 711500 T2953 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 711506 T2953 oasc.Overseer.start Overseer (id=91012483249209348-127.0.0.1:43728_solr-n_0000000000) starting
[junit4] 2> 711512 T2953 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4] 2> 711521 T2953 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4] 2> 711531 T2953 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4] 2> 711537 T3016 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 711543 T3015 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 711550 T3015 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 711552 T3015 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> 711552 T3015 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1, shard2, shard3, shard4, shard5, shard6, shard7, shard8, shard9, shard10, shard11, shard12]
[junit4] 2> 711553 T3015 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 711559 T3014 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 711562 T3011 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> 711562 T3002 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> 712045 T2953 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 712068 T2953 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 712084 T3014 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 712087 T2953 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 712091 T3015 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 712096 T3002 oascc.ZkStateReader$3.process Updating live nodes... (0)
[junit4] 2> 712097 T3011 oascc.ZkStateReader$3.process Updating live nodes... (0)
[junit4] 2> 712103 T2953 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:43728 43728
[junit4] 2> 712167 T2975 oasc.LeaderElector$1.process WARN org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /collections/collection1/leader_elect/shard2/election
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] 2> at org.apache.zookeeper.ZooKeeper.getChildren(ZooKeeper.java:1468)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:256)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:253)
[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:253)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:93)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.access$000(LeaderElector.java:55)
[junit4] 2> at org.apache.solr.cloud.LeaderElector$1.process(LeaderElector.java:138)
[junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:519)
[junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:495)
[junit4] 2>
[junit4] 2> 712242 T2975 oasc.LeaderElector$1.process WARN org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /collections/collection1/leader_elect/shard3/election
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] 2> at org.apache.zookeeper.ZooKeeper.getChildren(ZooKeeper.java:1468)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:256)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:253)
[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:253)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:93)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.access$000(LeaderElector.java:55)
[junit4] 2> at org.apache.solr.cloud.LeaderElector$1.process(LeaderElector.java:138)
[junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:519)
[junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:495)
[junit4] 2>
[junit4] 2> 712243 T2953 oas.SolrTestCaseJ4.tearDown ###Ending testPlaceholders
[junit4] 2> 712243 T2975 oasc.LeaderElector$1.process WARN org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /collections/collection1/leader_elect/shard1/election
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] 2> at org.apache.zookeeper.ZooKeeper.getChildren(ZooKeeper.java:1468)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:256)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:253)
[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:253)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:93)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.access$000(LeaderElector.java:55)
[junit4] 2> at org.apache.solr.cloud.LeaderElector$1.process(LeaderElector.java:138)
[junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:519)
[junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:495)
[junit4] 2>
[junit4] 1> client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 712251 T2953 oas.SolrTestCaseJ4.setUp ###Starting testOverseerFailure
[junit4] 2> 712252 T2953 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4] 2> 712253 T3017 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4] 2> 712353 T2953 oasc.ZkTestServer.run start zk server on port:44728
[junit4] 2> 712355 T2953 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 712359 T3024 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@2d6f4fcd name:ZooKeeperConnection Watcher:127.0.0.1:44728/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 712359 T2953 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 712361 T2953 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 712363 T3027 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@3596f070 name:ZooKeeperConnection Watcher:127.0.0.1:44728 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 712364 T2953 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 712421 T2953 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 712423 T3030 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@8944e2a name:ZooKeeperConnection Watcher:127.0.0.1:44728 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 712424 T2953 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 712424 T2953 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 712431 T2953 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4] 2> 712437 T2953 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4] 2> 712443 T2953 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4] 2> 712448 T2953 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 712456 T2953 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 712459 T3033 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@6efcc0b1 name:ZooKeeperConnection Watcher:127.0.0.1:44728/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 712459 T2953 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 712462 T2953 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 712469 T2953 oascc.SolrZkClient.makePath makePath: /live_nodes/node1
[junit4] 2> 712476 T3024 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 712477 T3033 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 712479 T2953 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 712481 T3036 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@6f7adf19 name:ZooKeeperConnection Watcher:127.0.0.1:44728/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 712481 T2953 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 712484 T2953 oascc.SolrZkClient.makePath makePath: /overseer_elect
[junit4] 2> 712491 T2953 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4] 2> 712501 T2953 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 712507 T2953 oasc.Overseer.start Overseer (id=91012483313434628-127.0.0.1:44728_solr-n_0000000000) starting
[junit4] 2> 712513 T2953 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4] 2> 712523 T2953 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4] 2> 712531 T2953 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4] 2> 712538 T3038 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 712541 T3037 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 713543 T3036 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 713547 T3037 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 713549 T3037 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> 713549 T3037 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1]
[junit4] 2> 713549 T3037 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 713556 T3036 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 713558 T3033 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> 713558 T3024 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> 714044 T2953 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 714067 T2953 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 714082 T3036 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 714085 T2953 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 714089 T3037 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 714096 T2953 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 714097 T3036 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 714104 T3037 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> 714104 T3037 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 714112 T3036 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 714221 T3024 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> 714221 T3033 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> 715280 T2953 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 715294 T2953 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 715296 T3041 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@72a597f1 name:ZooKeeperConnection Watcher:127.0.0.1:44728/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 715296 T2953 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 715301 T2953 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 715307 T2953 oasc.Overseer.start Overseer (id=91012483313434629-127.0.0.1:44728_solr-n_0000000001) starting
[junit4] 2> 715318 T3043 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 715323 T3042 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 715330 T3042 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 715331 T3042 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> 715331 T3042 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 715335 T3041 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 715337 T3033 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> 715337 T3024 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> 715394 T3041 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 715395 T2953 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 715401 T3042 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 715418 T2953 oasc.LeaderElector.checkIfIamLeader WARN Failed setting watch org.apache.zookeeper.KeeperException$NoNodeException: KeeperErrorCode = NoNode for /collections/collection1/leader_elect/shard1/election/91012483313434627-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:1151)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:273)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:270)
[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:270)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:126)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.joinElection(LeaderElector.java:277)
[junit4] 2> at org.apache.solr.cloud.OverseerTest$MockZKController.publishState(OverseerTest.java:153)
[junit4] 2> at org.apache.solr.cloud.OverseerTest.testOverseerFailure(OverseerTest.java:584)
[junit4] 2> at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
[junit4] 2> at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
[junit4] 2> at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
[junit4] 2> at java.lang.reflect.Method.invoke(Method.java:597)
[junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1559)
[junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner.access$600(RandomizedRunner.java:79)
[junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:737)
[junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:773)
[junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:787)
[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:70)
[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:358)
[junit4] 2> at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:782)
[junit4] 2> at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:442)
[junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:746)
[junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:648)
[junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:682)
[junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:693)
[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 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:70)
[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:358)
[junit4] 2> at java.lang.Thread.run(Thread.java:662)
[junit4] 2>
[junit4] 2> 715425 T3033 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 715426 T2953 oasc.LeaderElector.checkIfIamLeader WARN Failed setting watch org.apache.zookeeper.KeeperException$NoNodeException: KeeperErrorCode = NoNode for /collections/collection1/leader_elect/shard1/election/91012483313434627-node1_core1-n_0000000001
[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:1151)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:273)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:270)
[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:270)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:126)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:157)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.joinElection(LeaderElector.java:277)
[junit4] 2> at org.apache.solr.cloud.OverseerTest$MockZKController.publishState(OverseerTest.java:153)
[junit4] 2> at org.apache.solr.cloud.OverseerTest.testOverseerFailure(OverseerTest.java:584)
[junit4] 2> at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
[junit4] 2> at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
[junit4] 2> at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
[junit4] 2> at java.lang.reflect.Method.invoke(Method.java:597)
[junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1559)
[junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner.access$600(RandomizedRunner.java:79)
[junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:737)
[junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:773)
[junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:787)
[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:70)
[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:358)
[junit4] 2> at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:782)
[junit4] 2> at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:442)
[junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:746)
[junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:648)
[junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:682)
[junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:693)
[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 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:70)
[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:358)
[junit4] 2> at java.lang.Thread.run(Thread.java:662)
[junit4] 2>
[junit4] 2> 715428 T3042 oasc.SolrException.log ERROR Problem cleaning up collection in zk:collection1:org.apache.zookeeper.KeeperException$NotEmptyException: KeeperErrorCode = Directory not empty for /collections/collection1/leader_elect/shard1/election
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:125)
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] 2> at org.apache.zookeeper.ZooKeeper.delete(ZooKeeper.java:873)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$2.execute(SolrZkClient.java:173)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$2.execute(SolrZkClient.java:170)
[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:170)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.clean(SolrZkClient.java:654)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.clean(SolrZkClient.java:649)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.clean(SolrZkClient.java:649)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.clean(SolrZkClient.java:649)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.removeCore(Overseer.java:875)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.processMessage(Overseer.java:226)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.run(Overseer.java:187)
[junit4] 2> at java.lang.Thread.run(Thread.java:662)
[junit4] 2>
[junit4] 2> 715434 T2953 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 715439 T3041 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 715448 T3041 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 715453 T3042 oasc.Overseer$ClusterStateUpdater.setShardLeader ERROR Could not mark shard leader for non existing collection:collection1
[junit4] 2> 715454 T3024 oascc.ZkStateReader$3.process Updating live nodes... (0)
[junit4] 2> 715456 T3033 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 715463 T2953 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:44728 44728
[junit4] 2> 715535 T2953 oas.SolrTestCaseJ4.tearDown ###Ending testOverseerFailure
[junit4] 1> client port:0.0.0.0/0.0.0.0:0
[junit4] 2> NOTE: reproduce with: ant test -Dtestcase=OverseerTest -Dtests.method=testOverseerFailure -Dtests.seed=DC4888080066F44D -Dtests.multiplier=3 -Dtests.slow=true -Dtests.locale=es_ES -Dtests.timezone=Brazil/Acre -Dtests.file.encoding=UTF-8
[junit4] ERROR 3.31s J0 | OverseerTest.testOverseerFailure <<<
[junit4] > Throwable #1: org.apache.zookeeper.KeeperException$NodeExistsException: KeeperErrorCode = NodeExists for /collections/collection1/leaders/shard1
[junit4] > at __randomizedtesting.SeedInfo.seed([DC4888080066F44D:D84007FB12C31B6C]:0)
[junit4] > at org.apache.zookeeper.KeeperException.create(KeeperException.java:119)
[junit4] > at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] > at org.apache.zookeeper.ZooKeeper.create(ZooKeeper.java:783)
[junit4] > at org.apache.solr.common.cloud.SolrZkClient$10.execute(SolrZkClient.java:428)
[junit4] > at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
[junit4] > at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:425)
[junit4] > at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:382)
[junit4] > at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:369)
[junit4] > at org.apache.solr.cloud.ShardLeaderElectionContextBase.runLeaderProcess(ElectionContext.java:112)
[junit4] > at org.apache.solr.cloud.LeaderElector.runIamLeaderProcess(LeaderElector.java:165)
[junit4] > at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:109)
[junit4] > at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:157)
[junit4] > at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:157)
[junit4] > at org.apache.solr.cloud.LeaderElector.joinElection(LeaderElector.java:277)
[junit4] > at org.apache.solr.cloud.OverseerTest$MockZKController.publishState(OverseerTest.java:153)
[junit4] > at org.apache.solr.cloud.OverseerTest.testOverseerFailure(OverseerTest.java:584)
[junit4] > at java.lang.Thread.run(Thread.java:662)
[junit4] 2> 715561 T2953 oas.SolrTestCaseJ4.setUp ###Starting testShardLeaderChange
[junit4] 2> 715561 T2953 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4] 2> 715562 T3044 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4] 2> 715662 T2953 oasc.ZkTestServer.run start zk server on port:41264
[junit4] 2> 715664 T2953 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 715668 T3051 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@106eef56 name:ZooKeeperConnection Watcher:127.0.0.1:41264/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 715668 T2953 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 715669 T2953 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 715671 T3054 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@39874d3b name:ZooKeeperConnection Watcher:127.0.0.1:41264 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 715672 T2953 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 715730 T2953 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 715733 T3057 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@73034bc name:ZooKeeperConnection Watcher:127.0.0.1:41264 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 715733 T2953 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 715734 T2953 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 715741 T2953 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4] 2> 715748 T3058 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 715748 T2953 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 715750 T3063 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@453b00a3 name:ZooKeeperConnection Watcher:127.0.0.1:41264/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 715750 T3058 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 715752 T3064 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@5857348c name:ZooKeeperConnection Watcher:127.0.0.1:41264/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 715752 T2953 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 715752 T3058 oascc.SolrZkClient.makePath makePath: /overseer_elect
[junit4] 2> 715754 T2953 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4] 2> 715782 T3058 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4] 2> 715786 T2953 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4] 2> 715793 T2953 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 715800 T3058 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 715804 T2953 oascc.SolrZkClient.makePath makePath: /live_nodes/node1
[junit4] 2> 715808 T3058 oasc.Overseer.start Overseer (id=91012483530620931-127.0.0.1:41264_solr-n_0000000000) starting
[junit4] 2> 715814 T3064 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 715815 T3058 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4] 2> 715826 T3058 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4] 2> 715834 T3058 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4] 2> 715840 T3058 oasc.OverseerTest$OverseerRestarter.run Killing overseer.
[junit4] 2> 715840 T3066 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 715843 T3058 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 715846 T3069 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@2fc84bfd name:ZooKeeperConnection Watcher:127.0.0.1:41264/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 715846 T3058 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 715855 T3058 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 715862 T3058 oasc.Overseer.start Overseer (id=91012483530620933-127.0.0.1:41264_solr-n_0000000001) starting
[junit4] 2> 715873 T3071 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 715876 T3070 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 715882 T3070 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 715884 T3070 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"state1",
[junit4] 2> "node_name":"node1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node1/solr/"}
[junit4] 2> 715884 T3070 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1]
[junit4] 2> 715884 T3070 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 715891 T3069 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 715893 T3064 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> 716324 T2953 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 716347 T2953 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 716363 T3069 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 716369 T3069 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 716370 T2953 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 716370 T3070 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 716386 T3070 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"state2",
[junit4] 2> "node_name":"node1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node1/solr/"}
[junit4] 2> 716386 T3070 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 716393 T2953 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 716394 T3069 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 716396 T3074 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@5502736c name:ZooKeeperConnection Watcher:127.0.0.1:41264/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 716396 T2953 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 716400 T2953 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 716407 T2953 oascc.SolrZkClient.makePath makePath: /live_nodes/node2
[junit4] 2> 716415 T3064 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 716415 T3074 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 716421 T3069 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 716422 T2953 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 716426 T3070 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"state1",
[junit4] 2> "node_name":"node1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node1/solr/"}
[junit4] 2> 716426 T3070 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 716434 T3069 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 716443 T2953 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 716542 T3074 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 716542 T3064 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 716647 T2953 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 716655 T3069 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 716655 T3069 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 716655 T3069 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 716659 T3070 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 716661 T3070 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"state2",
[junit4] 2> "node_name":"node2",
[junit4] 2> "core":"core4",
[junit4] 2> "core_node_name":"node2",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node2/solr/"}
[junit4] 2> 716661 T3070 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=1
[junit4] 2> 716662 T3070 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 716667 T3069 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 716773 T3074 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 716773 T3064 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 716957 T3033 oasc.LeaderElector$1.process WARN org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /collections
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] 2> at org.apache.zookeeper.ZooKeeper.exists(ZooKeeper.java:1041)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$3.execute(SolrZkClient.java:205)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$3.execute(SolrZkClient.java:202)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.exists(SolrZkClient.java:202)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:413)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:382)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:369)
[junit4] 2> at org.apache.solr.cloud.ShardLeaderElectionContextBase.runLeaderProcess(ElectionContext.java:112)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.runIamLeaderProcess(LeaderElector.java:165)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:109)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.access$000(LeaderElector.java:55)
[junit4] 2> at org.apache.solr.cloud.LeaderElector$1.process(LeaderElector.java:138)
[junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:519)
[junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:495)
[junit4] 2>
[junit4] 2> 716958 T3033 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4] 2> 717155 T2953 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 717175 T3074 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 717176 T3064 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 717180 T2953 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 717182 T3074 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 717195 T3069 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 717195 T3069 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 717196 T3069 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 717200 T3070 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 717209 T3069 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 717315 T3074 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> 717342 T3066 oasc.OverseerCollectionProcessor.amILeader org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /overseer_elect/leader
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] 2> at org.apache.zookeeper.ZooKeeper.getData(ZooKeeper.java:1151)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:273)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:270)
[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:270)
[junit4] 2> at org.apache.solr.cloud.OverseerCollectionProcessor.amILeader(OverseerCollectionProcessor.java:204)
[junit4] 2> at org.apache.solr.cloud.OverseerCollectionProcessor.run(OverseerCollectionProcessor.java:156)
[junit4] 2> at java.lang.Thread.run(Thread.java:662)
[junit4] 2>
[junit4] 2> 717343 T3066 oasc.OverseerCollectionProcessor.amILeader According to ZK I (id=91012483530620931-127.0.0.1:41264_solr-n_0000000000) am no longer a leader.
[junit4] 2> 717343 T3065 oasc.Overseer$ClusterStateUpdater.run WARN Solr cannot talk to ZK, exiting Overseer work queue loop org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /overseer/queue-work
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] 2> at org.apache.zookeeper.ZooKeeper.getChildren(ZooKeeper.java:1468)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:256)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:253)
[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:253)
[junit4] 2> at org.apache.solr.cloud.DistributedQueue.orderedChildren(DistributedQueue.java:89)
[junit4] 2> at org.apache.solr.cloud.DistributedQueue.element(DistributedQueue.java:131)
[junit4] 2> at org.apache.solr.cloud.DistributedQueue.peek(DistributedQueue.java:325)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.run(Overseer.java:105)
[junit4] 2> at java.lang.Thread.run(Thread.java:662)
[junit4] 2>
[junit4] 2> 717343 T3066 oasc.OverseerCollectionProcessor.amILeader org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /overseer_elect/leader
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] 2> at org.apache.zookeeper.ZooKeeper.getData(ZooKeeper.java:1151)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:273)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:270)
[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:270)
[junit4] 2> at org.apache.solr.cloud.OverseerCollectionProcessor.amILeader(OverseerCollectionProcessor.java:204)
[junit4] 2> at org.apache.solr.cloud.OverseerCollectionProcessor.run(OverseerCollectionProcessor.java:163)
[junit4] 2> at java.lang.Thread.run(Thread.java:662)
[junit4] 2>
[junit4] 2> 717345 T3066 oasc.OverseerCollectionProcessor.amILeader According to ZK I (id=91012483530620931-127.0.0.1:41264_solr-n_0000000000) am no longer a leader.
[junit4] 2> 717384 T2953 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 717386 T2953 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 717389 T3077 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@17e36931 name:ZooKeeperConnection Watcher:127.0.0.1:41264/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 717389 T2953 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 717393 T2953 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 717401 T2953 oascc.SolrZkClient.makePath makePath: /live_nodes/node1
[junit4] 2> 717408 T3074 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 717409 T3077 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 717415 T3069 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 717415 T2953 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 717415 T3069 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 717416 T3069 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 717421 T3070 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4
[...truncated too long message...]
s... (8)
[junit4] 2> 741047 T3483 oascc.ZkStateReader$3.process Updating live nodes... (8)
[junit4] 2> 741047 T3477 oascc.ZkStateReader$3.process Updating live nodes... (8)
[junit4] 2> 741047 T3471 oascc.ZkStateReader$3.process Updating live nodes... (8)
[junit4] 2> 741048 T3486 oascc.ZkStateReader$3.process Updating live nodes... (8)
[junit4] 2> 741048 T3465 oascc.ZkStateReader$3.process Updating live nodes... (8)
[junit4] 2> 741049 T3474 oascc.ZkStateReader$3.process Updating live nodes... (8)
[junit4] 2> 741050 T3468 oascc.ZkStateReader$3.process Updating live nodes... (8)
[junit4] 2> 741051 T3480 oascc.ZkStateReader$3.process Updating live nodes... (8)
[junit4] 2> 741055 T3489 oascc.ZkStateReader$3.process Updating live nodes... (7)
[junit4] 2> 741056 T3480 oascc.ZkStateReader$3.process Updating live nodes... (7)
[junit4] 2> 741056 T3486 oascc.ZkStateReader$3.process Updating live nodes... (7)
[junit4] 2> 741057 T3474 oascc.ZkStateReader$3.process Updating live nodes... (7)
[junit4] 2> 741058 T3471 oascc.ZkStateReader$3.process Updating live nodes... (7)
[junit4] 2> 741058 T3468 oascc.ZkStateReader$3.process Updating live nodes... (7)
[junit4] 2> 741059 T3477 oascc.ZkStateReader$3.process Updating live nodes... (7)
[junit4] 2> 741059 T3483 oascc.ZkStateReader$3.process Updating live nodes... (7)
[junit4] 2> 741063 T3480 oascc.ZkStateReader$3.process Updating live nodes... (6)
[junit4] 2> 741064 T3477 oascc.ZkStateReader$3.process Updating live nodes... (6)
[junit4] 2> 741064 T3489 oascc.ZkStateReader$3.process Updating live nodes... (6)
[junit4] 2> 741064 T3474 oascc.ZkStateReader$3.process Updating live nodes... (6)
[junit4] 2> 741064 T3486 oascc.ZkStateReader$3.process Updating live nodes... (6)
[junit4] 2> 741065 T3483 oascc.ZkStateReader$3.process Updating live nodes... (6)
[junit4] 2> 741065 T3471 oascc.ZkStateReader$3.process Updating live nodes... (6)
[junit4] 2> 741070 T3489 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4] 2> 741070 T3486 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4] 2> 741070 T3483 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4] 2> 741071 T3474 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4] 2> 741073 T3477 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4] 2> 741080 T3480 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4] 2> 741083 T3483 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 741085 T3477 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 741086 T3489 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 741086 T3480 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 741087 T3486 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 741090 T3486 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 741092 T3483 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 741092 T3489 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 741093 T3480 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 741097 T3486 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 741097 T3489 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 741098 T3483 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 741103 T3486 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 741104 T3489 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 741106 T3489 oascc.ZkStateReader$3.process Updating live nodes... (0)
[junit4] 2> 741108 T2953 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:40681 40681
[junit4] 2> 741183 T2953 oas.SolrTestCaseJ4.tearDown ###Ending testShardAssignmentBigger
[junit4] 1> client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 741184 T2953 oas.SolrTestCaseJ4.initCore ####initCore
[junit4] 2> 741185 T2953 oas.SolrTestCaseJ4.initCore ####initCore end
[junit4] 2> 741816 T3387 oasc.LeaderElector$1.process WARN org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /collections/collection1/leaders/shard15
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] 2> at org.apache.zookeeper.ZooKeeper.exists(ZooKeeper.java:1041)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$3.execute(SolrZkClient.java:205)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$3.execute(SolrZkClient.java:202)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.exists(SolrZkClient.java:202)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:413)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:382)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:369)
[junit4] 2> at org.apache.solr.cloud.ShardLeaderElectionContextBase.runLeaderProcess(ElectionContext.java:112)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.runIamLeaderProcess(LeaderElector.java:165)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:109)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.access$000(LeaderElector.java:55)
[junit4] 2> at org.apache.solr.cloud.LeaderElector$1.process(LeaderElector.java:138)
[junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:519)
[junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:495)
[junit4] 2>
[junit4] 2> 741817 T3387 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4] 2> 744185 T2953 oas.SolrTestCaseJ4.deleteCore ###deleteCore
[junit4] 2> NOTE: test params are: codec=Lucene46: {}, docValues:{}, sim=RandomSimilarityProvider(queryNorm=false,coord=yes): {}, locale=es_ES, timezone=Brazil/Acre
[junit4] 2> NOTE: Linux 3.8.0-34-generic amd64/Sun Microsystems Inc. 1.6.0_45 (64-bit)/cpus=8,threads=1,free=55515368,total=169099264
[junit4] 2> NOTE: All tests run in this JVM: [TestManagedSchema, FieldMutatingUpdateProcessorTest, HdfsBasicDistributedZk2Test, DistributedTermsComponentTest, TestReversedWildcardFilterFactory, UpdateParamsTest, ResourceLoaderTest, SynonymTokenizerTest, BinaryUpdateRequestHandlerTest, FileBasedSpellCheckerTest, JsonLoaderTest, SolrInfoMBeanTest, TestPostingsSolrHighlighter, ChangedSchemaMergeTest, TestRealTimeGet, QueryEqualityTest, TestSolrXMLSerializer, TestSolrQueryParser, ShowFileRequestHandlerTest, HdfsCollectionsAPIDistributedZkTest, HdfsUnloadDistributedZkTest, TestStressUserVersions, MoreLikeThisHandlerTest, TestSort, TestValueSourceCache, SpatialFilterTest, QueryResultKeyTest, TestBadConfig, BadCopyFieldTest, TestAnalyzeInfixSuggestions, TestReloadAndDeleteDocs, TestCoreContainer, TestFieldTypeCollectionResource, PrimitiveFieldTypeTest, TestLMDirichletSimilarityFactory, TestSolrXmlPersistor, URLClassifyProcessorTest, EchoParamsTest, TestSearchPerf, BasicFunctionalityTest, WordBreakSolrSpellCheckerTest, TestJoin, ExternalFileFieldSortTest, TestDocumentBuilder, TestCopyFieldCollectionResource, BJQParserTest, IndexSchemaTest, UnloadDistributedZkTest, ShardRoutingTest, CSVRequestHandlerTest, DeleteReplicaTest, TestAddFieldRealTimeGet, TestPHPSerializedResponseWriter, TestTrie, TestFaceting, TestPerFieldSimilarity, AnalysisAfterCoreReloadTest, SpellPossibilityIteratorTest, TestDocBasedVersionConstraints, SOLR749Test, SolrTestCaseJ4Test, SoftAutoCommitTest, TestQueryUtils, TestElisionMultitermQuery, TestJmxMonitoredMap, CircularListTest, CacheHeaderTest, SuggesterTest, TestFileDictionaryLookup, SliceStateTest, SolrXmlInZkTest, LeaderElectionTest, TestStressVersions, TestSchemaSimilarityResource, HdfsDirectoryTest, QueryElevationComponentTest, SystemInfoHandlerTest, SuggesterFSTTest, UUIDFieldTest, RecoveryZkTest, SolrCoreTest, TestHighFrequencyDictionaryFactory, BasicDistributedZkTest, ScriptEngineTest, ChaosMonkeySafeLeaderTest, SyncSliceTest, OverseerTest]
[junit4] Completed on J0 in 37.12s, 8 tests, 1 error <<< FAILURES!
[...truncated 573 lines...]
BUILD FAILED
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/build.xml:459: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/build.xml:439: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/build.xml:39: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/extra-targets.xml:37: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build.xml:189: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/common-build.xml:491: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/lucene/common-build.xml:1307: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/lucene/common-build.xml:940: There were test failures: 348 suites, 1522 tests, 1 error, 35 ignored (6 assumptions)
Total time: 43 minutes 5 seconds
Build step 'Invoke Ant' marked build as failure
Description set: Java: 64bit/jdk1.6.0_45 -XX:+UseCompressedOops -XX:+UseSerialGC
Archiving artifacts
Recording test results
Email was triggered for: Failure
Sending email for trigger: Failure