You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@lucene.apache.org by Apache Jenkins Server <je...@builds.apache.org> on 2013/11/24 17:41:15 UTC
[JENKINS] Lucene-Solr-Tests-4.x-Java6 - Build # 2188 - Still
Failing
Build: https://builds.apache.org/job/Lucene-Solr-Tests-4.x-Java6/2188/
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([A509AA2453043997:A10125D741A1D6B6]: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:424)
at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:65)
at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:421)
at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:378)
at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:365)
at org.apache.solr.cloud.ShardLeaderElectionContextBase.runLeaderProcess(ElectionContext.java:102)
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.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:57)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:616)
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:679)
Build Log:
[...truncated 9874 lines...]
[junit4] Suite: org.apache.solr.cloud.OverseerTest
[junit4] 2> 1195082 T2206 oas.SolrTestCaseJ4.initCore ####initCore
[junit4] 2> Creating dataDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./solrtest-OverseerTest-1385310296022
[junit4] 2> 1195083 T2206 oas.SolrTestCaseJ4.initCore ####initCore end
[junit4] 2> 1195087 T2206 oas.SolrTestCaseJ4.setUp ###Starting testOverseerFailure
[junit4] 2> 1195088 T2206 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4] 2> 1195088 T2207 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4] 2> 1195189 T2206 oasc.ZkTestServer.run start zk server on port:12858
[junit4] 2> 1195190 T2206 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1195193 T2213 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@9ad50d9 name:ZooKeeperConnection Watcher:127.0.0.1:12858/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1195194 T2206 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1195195 T2206 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1195196 T2215 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@51743cd1 name:ZooKeeperConnection Watcher:127.0.0.1:12858 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1195197 T2206 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1195208 T2206 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1195210 T2217 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@3b531475 name:ZooKeeperConnection Watcher:127.0.0.1:12858 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1195210 T2206 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1195210 T2206 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 1195215 T2206 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4] 2> 1195224 T2206 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4] 2> 1195226 T2206 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4] 2> 1195228 T2206 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 1195231 T2206 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1195233 T2219 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@5eddb023 name:ZooKeeperConnection Watcher:127.0.0.1:12858/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1195233 T2206 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1195234 T2206 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 1195236 T2206 oascc.SolrZkClient.makePath makePath: /live_nodes/node1
[junit4] 2> 1195239 T2213 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 1195239 T2219 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 1195239 T2206 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1195241 T2221 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@412a59d2 name:ZooKeeperConnection Watcher:127.0.0.1:12858/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1195241 T2206 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1195242 T2206 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4] 2> 1195253 T2206 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 1195255 T2206 oasc.Overseer.start Overseer (id=90787695560818692-127.0.0.1:12858_solr-n_0000000000) starting
[junit4] 2> 1195257 T2206 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4] 2> 1195260 T2206 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4] 2> 1195264 T2206 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4] 2> 1195266 T2223 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 1195267 T2222 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 1196269 T2221 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1196271 T2222 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1196271 T2222 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> 1196272 T2222 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1]
[junit4] 2> 1196272 T2222 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 1196281 T2221 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1196282 T2219 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> 1196282 T2213 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> 1196770 T2206 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 1196789 T2206 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 1196794 T2221 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1196795 T2206 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1196796 T2222 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1196798 T2221 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1196798 T2206 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 1196800 T2222 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> 1196800 T2222 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 1196803 T2221 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1196905 T2213 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> 1196905 T2219 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> 1197960 T2206 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 1197976 T2206 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1197978 T2225 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@3e8e8d8f name:ZooKeeperConnection Watcher:127.0.0.1:12858/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1197978 T2206 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1197981 T2206 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 1197983 T2206 oasc.Overseer.start Overseer (id=90787695560818693-127.0.0.1:12858_solr-n_0000000001) starting
[junit4] 2> 1197988 T2227 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 1197988 T2226 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 1197990 T2226 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1197991 T2226 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> 1197991 T2226 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 1197994 T2225 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1197995 T2219 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> 1197995 T2213 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> 1198048 T2225 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1198048 T2206 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 1198049 T2226 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1198060 T2206 oasc.LeaderElector.checkIfIamLeader WARN Failed setting watch org.apache.zookeeper.KeeperException$NoNodeException: KeeperErrorCode = NoNode for /collections/collection1/leader_elect/shard1/election/90787695560818691-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:269)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:266)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:65)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.getData(SolrZkClient.java:266)
[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:57)
[junit4] 2> at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
[junit4] 2> at java.lang.reflect.Method.invoke(Method.java:616)
[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:679)
[junit4] 2>
[junit4] 2> 1198062 T2219 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 1198063 T2226 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:169)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$2.execute(SolrZkClient.java:166)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:65)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.delete(SolrZkClient.java:166)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.clean(SolrZkClient.java:650)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.clean(SolrZkClient.java:645)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.clean(SolrZkClient.java:645)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.clean(SolrZkClient.java:645)
[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:224)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.run(Overseer.java:185)
[junit4] 2> at java.lang.Thread.run(Thread.java:679)
[junit4] 2>
[junit4] 2> 1198063 T2206 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 1198066 T2225 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1198068 T2225 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1198069 T2213 oascc.ZkStateReader$3.process Updating live nodes... (0)
[junit4] 2> 1198070 T2226 oasc.Overseer$ClusterStateUpdater.setShardLeader ERROR Could not mark shard leader for non existing collection:collection1
[junit4] 2> 1198073 T2206 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:12858 12858
[junit4] 2> 1198140 T2206 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=A509AA2453043997 -Dtests.multiplier=3 -Dtests.slow=true -Dtests.locale=es_SV -Dtests.timezone=CST6CDT -Dtests.file.encoding=US-ASCII
[junit4] ERROR 3.08s J0 | OverseerTest.testOverseerFailure <<<
[junit4] > Throwable #1: org.apache.zookeeper.KeeperException$NodeExistsException: KeeperErrorCode = NodeExists for /collections/collection1/leaders/shard1
[junit4] > at __randomizedtesting.SeedInfo.seed([A509AA2453043997:A10125D741A1D6B6]: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:424)
[junit4] > at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:65)
[junit4] > at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:421)
[junit4] > at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:378)
[junit4] > at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:365)
[junit4] > at org.apache.solr.cloud.ShardLeaderElectionContextBase.runLeaderProcess(ElectionContext.java:102)
[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.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:679)
[junit4] 2> 1198165 T2206 oas.SolrTestCaseJ4.setUp ###Starting testStateChange
[junit4] 2> 1198165 T2206 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4] 2> 1198166 T2228 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4] 2> 1198267 T2206 oasc.ZkTestServer.run start zk server on port:27049
[junit4] 2> 1198268 T2206 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1198271 T2234 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@742d87c name:ZooKeeperConnection Watcher:127.0.0.1:27049/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1198271 T2206 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1198272 T2206 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1198274 T2236 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@59ab08a4 name:ZooKeeperConnection Watcher:127.0.0.1:27049 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1198274 T2206 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1198329 T2206 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1198330 T2238 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@7446115c name:ZooKeeperConnection Watcher:127.0.0.1:27049 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1198330 T2206 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1198331 T2206 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 1198334 T2206 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4] 2> 1198336 T2206 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4] 2> 1198338 T2206 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4] 2> 1198340 T2206 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 1198342 T2206 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1198344 T2240 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@5d8a1a9e name:ZooKeeperConnection Watcher:127.0.0.1:27049/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1198344 T2206 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1198345 T2206 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4] 2> 1198350 T2206 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 1198352 T2206 oasc.Overseer.start Overseer (id=90787695762669571-127.0.0.1:27049_solr-n_0000000000) starting
[junit4] 2> 1198355 T2206 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4] 2> 1198358 T2206 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4] 2> 1198361 T2206 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4] 2> 1198364 T2242 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 1198364 T2241 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 1198366 T2206 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1198366 T2241 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1198367 T2241 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=null message={
[junit4] 2> "operation":"state",
[junit4] 2> "base_url":"http://127.0.0.1/solr",
[junit4] 2> "node_name":"node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "core":"core1",
[junit4] 2> "roles":"",
[junit4] 2> "state":"recovering"}
[junit4] 2> 1198367 T2241 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 1198370 T2240 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1198370 T2234 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> 1198418 T2206 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1198420 T2240 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1198421 T2241 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1198422 T2241 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=null message={
[junit4] 2> "operation":"state",
[junit4] 2> "base_url":"http://127.0.0.1/solr",
[junit4] 2> "node_name":"node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "core":"core1",
[junit4] 2> "roles":"",
[junit4] 2> "state":"active"}
[junit4] 2> 1198422 T2241 oasc.Overseer$ClusterStateUpdater.updateState node=core_node1 is already registered
[junit4] 2> 1198422 T2241 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 1198431 T2240 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1198534 T2234 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> 1198576 T2206 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:27049 27049
[junit4] 2> 1199570 T2219 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 1199830 T2219 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:201)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$3.execute(SolrZkClient.java:198)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:65)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.exists(SolrZkClient.java:198)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:409)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:378)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:365)
[junit4] 2> at org.apache.solr.cloud.ShardLeaderElectionContextBase.runLeaderProcess(ElectionContext.java:102)
[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> 1199831 T2206 oas.SolrTestCaseJ4.tearDown ###Ending testStateChange
[junit4] 2> 1199832 T2219 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4] 1> client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 1199837 T2206 oas.SolrTestCaseJ4.setUp ###Starting testShardLeaderChange
[junit4] 2> 1199838 T2206 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4] 2> 1199838 T2243 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4] 2> 1199939 T2206 oasc.ZkTestServer.run start zk server on port:20331
[junit4] 2> 1199940 T2206 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1199944 T2249 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@4e22370e name:ZooKeeperConnection Watcher:127.0.0.1:20331/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1199944 T2206 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1199945 T2206 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1199953 T2251 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1926b4dc name:ZooKeeperConnection Watcher:127.0.0.1:20331 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1199954 T2206 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1199968 T2206 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1199970 T2253 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@6500913d name:ZooKeeperConnection Watcher:127.0.0.1:20331 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1199970 T2206 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1199970 T2206 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 1199973 T2206 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4] 2> 1199977 T2254 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1199977 T2206 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1199978 T2256 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@54d6740 name:ZooKeeperConnection Watcher:127.0.0.1:20331/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1199978 T2254 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1199978 T2258 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1cb59d78 name:ZooKeeperConnection Watcher:127.0.0.1:20331/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1199979 T2254 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4] 2> 1199979 T2206 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1199980 T2206 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4] 2> 1199982 T2206 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4] 2> 1199983 T2254 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 1199984 T2206 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 1199984 T2254 oasc.Overseer.start Overseer (id=90787695872114691-127.0.0.1:20331_solr-n_0000000000) starting
[junit4] 2> 1199986 T2254 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4] 2> 1199987 T2206 oascc.SolrZkClient.makePath makePath: /live_nodes/node1
[junit4] 2> 1199989 T2254 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4] 2> 1199989 T2258 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 1199992 T2254 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4] 2> 1199993 T2260 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 1199993 T2254 oasc.OverseerTest$OverseerRestarter.run Killing overseer.
[junit4] 2> 1199995 T2254 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1199996 T2262 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@520294f9 name:ZooKeeperConnection Watcher:127.0.0.1:20331/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1199996 T2254 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1199999 T2254 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 1200001 T2254 oasc.Overseer.start Overseer (id=90787695872114693-127.0.0.1:20331_solr-n_0000000001) starting
[junit4] 2> 1200005 T2264 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 1200005 T2263 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 1200007 T2263 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1200008 T2263 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> 1200008 T2263 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1]
[junit4] 2> 1200008 T2263 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 1200010 T2262 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1200011 T2258 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> 1200492 T2206 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 1200523 T2206 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 1200529 T2262 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1200531 T2262 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1200531 T2206 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 1200531 T2263 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1200535 T2263 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> 1200536 T2263 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 1200536 T2206 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1200538 T2266 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@3a2c3910 name:ZooKeeperConnection Watcher:127.0.0.1:20331/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1200538 T2206 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1200539 T2262 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1200540 T2206 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 1200542 T2206 oascc.SolrZkClient.makePath makePath: /live_nodes/node2
[junit4] 2> 1200544 T2258 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 1200544 T2266 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 1200546 T2262 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1200547 T2206 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 1200547 T2263 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> 1200548 T2263 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 1200550 T2262 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1200552 T2206 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1200653 T2258 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> 1200653 T2266 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> 1200654 T2206 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1200665 T2262 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1200665 T2262 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1200675 T2263 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1200676 T2263 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> 1200676 T2263 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=1
[junit4] 2> 1200676 T2263 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 1200679 T2262 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1200781 T2258 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> 1200781 T2266 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> 1201166 T2206 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 1201183 T2266 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 1201183 T2258 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 1201184 T2206 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1201184 T2266 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 1201189 T2262 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1201189 T2262 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1201189 T2262 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1201190 T2263 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1201193 T2262 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1201286 T2206 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1201296 T2266 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> 1201388 T2206 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1201390 T2206 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1201392 T2268 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@3afea8d0 name:ZooKeeperConnection Watcher:127.0.0.1:20331/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1201392 T2206 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1201393 T2206 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 1201396 T2206 oascc.SolrZkClient.makePath makePath: /live_nodes/node1
[junit4] 2> 1201398 T2266 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 1201398 T2268 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 1201409 T2262 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1201409 T2206 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 1201409 T2262 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1201409 T2262 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1201411 T2263 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1201411 T2263 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> 1201412 T2263 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 1201419 T2254 oasc.OverseerTest$OverseerRestarter.run Killing overseer.
[junit4] 2> 1201422 T2254 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1201424 T2270 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@6905191c name:ZooKeeperConnection Watcher:127.0.0.1:20331/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1201425 T2266 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 1201425 T2254 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1201425 T2268 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 1201427 T2268 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 1201428 T2206 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 1201428 T2254 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 1201431 T2254 oasc.Overseer.start Overseer (id=90787695872114696-127.0.0.1:20331_solr-n_0000000002) starting
[junit4] 2> 1201451 T2206 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1201453 T2274 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 1201453 T2273 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@65e86845 name:ZooKeeperConnection Watcher:127.0.0.1:20331/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1201453 T2206 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1201455 T2271 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1201455 T2206 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 1201455 T2271 oasc.Overseer$ClusterStateUpdater.run Replaying operations from work queue.
[junit4] 2> 1201456 T2271 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> 1201456 T2271 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 1201457 T2273 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> 1201457 T2206 oascc.SolrZkClient.makePath makePath: /live_nodes/node2
[junit4] 2> 1201457 T2268 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> 1201459 T2271 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 1201460 T2268 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 1201460 T2273 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 1201461 T2271 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1201462 T2271 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> 1201462 T2271 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 1201462 T2270 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1201462 T2206 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 1201466 T2273 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> 1201466 T2268 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> 1201469 T2206 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1201470 T2271 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1201470 T2271 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> 1201470 T2271 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 1201473 T2270 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1201476 T2270 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1201476 T2271 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> 1201477 T2271 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 1201479 T2270 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1201495 T2260 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:269)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:266)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:65)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.getData(SolrZkClient.java:266)
[junit4] 2> at org.apache.solr.cloud.OverseerCollectionProcessor.amILeader(OverseerCollectionProcessor.java:203)
[junit4] 2> at org.apache.solr.cloud.OverseerCollectionProcessor.run(OverseerCollectionProcessor.java:162)
[junit4] 2> at java.lang.Thread.run(Thread.java:679)
[junit4] 2>
[junit4] 2> 1201495 T2259 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:252)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:249)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:65)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.getChildren(SolrZkClient.java:249)
[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:103)
[junit4] 2> at java.lang.Thread.run(Thread.java:679)
[junit4] 2>
[junit4] 2> 1201495 T2260 oasc.OverseerCollectionProcessor.amILeader According to ZK I (id=90787695872114691-127.0.0.1:20331_solr-n_0000000000) am no longer a leader.
[junit4] 2> 1201571 T2206 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1201581 T2273 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> 1201581 T2268 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> 1201673 T2206 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1201676 T2270 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1201676 T2206 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 1201676 T2270 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1201677 T2270 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1201678 T2271 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1201678 T2271 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> 1201679 T2271 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 1201695 T2270 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1201696 T2273 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 1201696 T2268 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 1201697 T2206 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1201698 T2273 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 1201702 T2270 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1201705 T2270 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1201799 T2206 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1201808 T2273 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> 1201901 T2206 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1201903 T2206 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1201905 T2276 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@48d66f1f name:ZooKeeperConnection Watcher:127.0.0.1:20331/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1201905 T2206 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1201906 T2206 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 1201908 T2206 oascc.SolrZkClient.makePath makePath: /live_nodes/node1
[junit4] 2> 1201911 T2273 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 1201911 T2276 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 1201921 T2270 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1201921 T2206 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 1201922 T2270 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1201922 T2270 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1201923 T2271 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1201924 T2271 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> 1201924 T2271 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 1201936 T2270 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1201937 T2276 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 1201937 T2273 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 1201939 T2276 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 1201940 T2270 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1201940 T2206 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 1201941 T2271 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> 1201941 T2271 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 1201944 T2270 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1201947 T2206 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1201948 T2270 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1201949 T2278 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@7233533a name:ZooKeeperConnection Watcher:127.0.0.1:20331/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1201949 T2206 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1201951 T2206 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 1201953 T2206 oascc.SolrZkClient.makePath makePath: /live_nodes/node2
[junit4] 2> 1201955 T2276 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 1201955 T2278 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 1201957 T2254 oasc.OverseerTest$OverseerRestarter.run Killing overseer.
[junit4] 2> 1201957 T2270 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1201957 T2206 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 1201958 T2254 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1201960 T2280 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@430d802b name:ZooKeeperConnection Watcher:127.0.0.1:20331/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1201960 T2254 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1201963 T2254 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 1201963 T2206 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1201965 T2254 oasc.Overseer.start Overseer (id=90787695872114700-127.0.0.1:20331_solr-n_0000000003) starting
[junit4] 2> 1201970 T2282 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 1201971 T2281 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1201971 T2281 oasc.Overseer$ClusterStateUpdater.run Replaying operations from work queue.
[junit4] 2> 1201972 T2281 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> 1201972 T2281 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 1201973 T2278 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> 1201973 T2276 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> 1201976 T2281 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> 1201976 T2281 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 1201977 T2278 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> 1201977 T2276 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> 1201981 T2278 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> 1201981 T2276 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> 1201983 T2281 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 1201984 T2281 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1201985 T2281 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> 1201985 T2281 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 1201987 T2280 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1201988 T2278 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> 1201988 T2276 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> 1202065 T2206 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1202068 T2280 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1202069 T2206 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 1202070 T2281 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1202071 T2281 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> 1202071 T2281 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 1202080 T2280 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1202082 T2278 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 1202082 T2276 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 1202083 T2206 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1202084 T2278 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 1202088 T2280 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1202091 T2280 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1202185 T2206 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1202193 T2278 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> 1202287 T2206 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1202289 T2206 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1202290 T2284 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@7339ea2c name:ZooKeeperConnection Watcher:127.0.0.1:20331/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1202291 T2206 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1202292 T2206 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 1202294 T2206 oascc.SolrZkClient.makePath makePath: /live_nodes/node1
[junit4] 2> 1202297 T2278 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 1202297 T2284 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 1202306 T2280 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1202306 T2206 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 1202306 T2280 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1202307 T2280 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1202308 T2281 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1202309 T2281 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> 1202309 T2281 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 1202321 T2280 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1202323 T2284 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 1202323 T2278 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 1202325 T2284 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 1202326 T2280 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1202326 T2206 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 1202327 T2281 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> 1202327 T2281 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 1202330 T2280 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1202333 T2206 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1202334 T2280 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1202334 T2286 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@6209f0f2 name:ZooKeeperConnection Watcher:127.0.0.1:20331/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1202335 T2206 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1202336 T2206 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 1202338 T2206 oascc.SolrZkClient.makePath makePath: /live_nodes/node2
[junit4] 2> 1202340 T2284 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 1202341 T2286 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 1202342 T2280 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1202343 T2206 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 1202343 T2281 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> 1202344 T2281 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 1202346 T2280 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1202348 T2206 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1202373 T2254 oasc.OverseerTest$OverseerRestarter.run Killing overseer.
[junit4] 2> 1202374 T2254 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1202376 T2288 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@ac63ad8 name:ZooKeeperConnection Watcher:127.0.0.1:20331/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1202376 T2254 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1202379 T2254 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 1202381 T2254 oasc.Overseer.start Overseer (id=90787695872114703-127.0.0.1:20331_solr-n_0000000004) starting
[junit4] 2> 1202385 T2290 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 1202387 T2289 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1202387 T2289 oasc.Overseer$ClusterStateUpdater.run Replaying operations from work queue.
[junit4] 2> 1202388 T2289 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> 1202388 T2289 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 1202389 T2286 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> 1202389 T2284 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> 1202391 T2289 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> 1202391 T2289 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 1202392 T2284 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> 1202392 T2286 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> 1202396 T2286 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> 1202396 T2284 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> 1202398 T2289 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> 1202398 T2289 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 1202399 T2284 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> 1202399 T2286 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> 1202401 T2289 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 1202448 T2281 oasc.Overseer$ClusterStateUpdater.run WARN Solr cannot talk to ZK, exiting Overseer main queue loop org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /overseer/queue
[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:252)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:249)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:65)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.getChildren(SolrZkClient.java:249)
[junit4] 2> at org.apache.solr.cloud.DistributedQueue.orderedChildren(DistributedQueue.java:89)
[junit4] 2> at org.apache.solr.cloud.DistributedQueue.peek(DistributedQueue.java:411)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.run(Overseer.java:193)
[junit4] 2> at java.lang.Thread.run(Thread.java:679)
[junit4] 2>
[junit4] 2> 1202449 T2206 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1202452 T2288 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1202452 T2206 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 1202453 T2289 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1202454 T2289 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/"}
[...truncated too long message...]
n.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:65)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.getChildren(SolrZkClient.java:249)
[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> 1220575 T2583 oasc.LeaderElector$1.process WARN org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /collections/collection1/leader_elect/shard11/election/90787696780050504-node68_core68-n_0000000002
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] 2> at org.apache.zookeeper.ZooKeeper.getData(ZooKeeper.java:1151)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:269)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:266)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:65)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.getData(SolrZkClient.java:266)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:126)
[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> 1220575 T2583 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4] 2> 1220579 T2585 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4] 2> 1220596 T2599 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4] 2> 1220604 T2605 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard9
[junit4] 2> 1220604 T2605 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:201)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$3.execute(SolrZkClient.java:198)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:65)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.exists(SolrZkClient.java:198)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:409)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:378)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:365)
[junit4] 2> at org.apache.solr.cloud.ShardLeaderElectionContextBase.runLeaderProcess(ElectionContext.java:102)
[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> 1220604 T2605 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4] 2> 1220607 T2607 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.create(ZooKeeper.java:783)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$10.execute(SolrZkClient.java:424)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:65)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:421)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:378)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:365)
[junit4] 2> at org.apache.solr.cloud.ShardLeaderElectionContextBase.runLeaderProcess(ElectionContext.java:102)
[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> 1220607 T2607 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4] 2> 1222177 T2206 oas.SolrTestCaseJ4.deleteCore ###deleteCore
[junit4] 2> NOTE: test params are: codec=Lucene42, sim=DefaultSimilarity, locale=es_SV, timezone=CST6CDT
[junit4] 2> NOTE: FreeBSD 9.1-RELEASE-p3 amd64/Sun Microsystems Inc. 1.6.0_32 (64-bit)/cpus=16,threads=1,free=229364304,total=430112768
[junit4] 2> NOTE: All tests run in this JVM: [TestUniqueKeyFieldResource, TestReversedWildcardFilterFactory, TestSort, ResponseLogComponentTest, HdfsDirectoryTest, BinaryUpdateRequestHandlerTest, PolyFieldTest, AnalysisAfterCoreReloadTest, TestLuceneMatchVersion, TestNRTOpen, HdfsBasicDistributedZkTest, TestRealTimeGet, TestSolrXMLSerializer, RegexBoostProcessorTest, TestBadConfig, HdfsUnloadDistributedZkTest, TestFaceting, TestSearchPerf, SampleTest, TestFieldResource, RecoveryZkTest, TestSolrIndexConfig, HdfsRecoveryZkTest, MoreLikeThisHandlerTest, BasicDistributedZkTest, DateMathParserTest, DistributedTermsComponentTest, StressHdfsTest, ZkControllerTest, TestRecoveryHdfs, TestValueSourceCache, TestConfig, TestSolrQueryParser, TestSolrQueryParserResource, LoggingHandlerTest, TestManagedSchema, BasicFunctionalityTest, TestPseudoReturnFields, ShardSplitTest, IndexSchemaTest, StatelessScriptUpdateProcessorFactoryTest, TestQueryUtils, JsonLoaderTest, TestNoOpRegenerator, TestSolrDeletionPolicy1, TestLFUCache, TestModifyConfFiles, BlockDirectoryTest, SpellPossibilityIteratorTest, SolrInfoMBeanTest, SynonymTokenizerTest, CSVRequestHandlerTest, OverseerCollectionProcessorTest, LegacyHTMLStripCharFilterTest, SoftAutoCommitTest, TestPHPSerializedResponseWriter, TestRandomDVFaceting, UpdateRequestProcessorFactoryTest, SliceStateTest, TestCollationKeyRangeQueries, CacheHeaderTest, PrimitiveFieldTypeTest, URLClassifyProcessorTest, ReturnFieldsTest, DocumentBuilderTest, TestDocSet, TestLMDirichletSimilarityFactory, QueryParsingTest, ClusterStateUpdateTest, CachingDirectoryFactoryTest, CoreAdminHandlerTest, FileBasedSpellCheckerTest, ScriptEngineTest, UnloadDistributedZkTest, ParsingFieldUpdateProcessorsTest, TestSimpleQParserPlugin, TestCharFilters, TestWriterPerf, TestMaxScoreQueryParser, EnumFieldTest, DocValuesTest, CoreMergeIndexesAdminHandlerTest, ExternalFileFieldSortTest, BasicDistributedZk2Test, OverseerTest]
[junit4] Completed on J0 in 27.13s, 8 tests, 1 error <<< FAILURES!
[...truncated 532 lines...]
BUILD FAILED
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/build.xml:426: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/build.xml:406: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/build.xml:39: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/extra-targets.xml:37: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build.xml:189: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/common-build.xml:492: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/lucene/common-build.xml:1279: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/lucene/common-build.xml:912: There were test failures: 345 suites, 1505 tests, 1 error, 35 ignored (7 assumptions)
Total time: 65 minutes 2 seconds
Build step 'Invoke Ant' marked build as failure
Archiving artifacts
Recording test results
Email was triggered for: Failure
Sending email for trigger: Failure