You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@lucene.apache.org by Policeman Jenkins Server <je...@thetaphi.de> on 2014/02/15 18:16:46 UTC
[JENKINS] Lucene-Solr-4.x-Linux (64bit/jdk1.6.0_45) - Build # 9379
- Still Failing!
Build: http://jenkins.thetaphi.de/job/Lucene-Solr-4.x-Linux/9379/
Java: 64bit/jdk1.6.0_45 -XX:+UseCompressedOops -XX:+UseConcMarkSweepGC
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([A72E72EE4A20A0C2:A326FD1D58854FE3]: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:429)
at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:426)
at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:383)
at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:370)
at org.apache.solr.cloud.ShardLeaderElectionContextBase.runLeaderProcess(ElectionContext.java:112)
at org.apache.solr.cloud.LeaderElector.runIamLeaderProcess(LeaderElector.java:164)
at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:108)
at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:156)
at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:156)
at org.apache.solr.cloud.LeaderElector.joinElection(LeaderElector.java:289)
at org.apache.solr.cloud.OverseerTest$MockZKController.publishState(OverseerTest.java:153)
at org.apache.solr.cloud.OverseerTest.testOverseerFailure(OverseerTest.java:584)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
at java.lang.reflect.Method.invoke(Method.java:597)
at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1559)
at com.carrotsearch.randomizedtesting.RandomizedRunner.access$600(RandomizedRunner.java:79)
at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:737)
at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:773)
at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:787)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:50)
at org.apache.lucene.util.TestRuleFieldCacheSanity$1.evaluate(TestRuleFieldCacheSanity.java:51)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:49)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:782)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:442)
at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:746)
at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:648)
at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:682)
at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:693)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:42)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:43)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:55)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
at java.lang.Thread.run(Thread.java:662)
Build Log:
[...truncated 9984 lines...]
[junit4] Suite: org.apache.solr.cloud.OverseerTest
[junit4] 2> 1379658 T4224 oas.SolrTestCaseJ4.buildSSLConfig Randomized ssl (true) and clientAuth (false)
[junit4] 2> 1379659 T4224 oas.SolrTestCaseJ4.initCore ####initCore
[junit4] 2> Creating dataDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./solrtest-OverseerTest-1392484269186
[junit4] 2> 1379659 T4224 oas.SolrTestCaseJ4.initCore ####initCore end
[junit4] 2> 1379663 T4224 oas.SolrTestCaseJ4.setUp ###Starting testDoubleAssignment
[junit4] 2> 1379663 T4224 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4] 2> 1379664 T4225 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4] 2> 1379764 T4224 oasc.ZkTestServer.run start zk server on port:52526
[junit4] 2> 1379765 T4224 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1379840 T4231 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@3aaeb16c name:ZooKeeperConnection Watcher:127.0.0.1:52526/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1379841 T4224 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1379844 T4224 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1379846 T4233 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@12dab407 name:ZooKeeperConnection Watcher:127.0.0.1:52526 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1379846 T4224 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1379851 T4224 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1379854 T4235 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@3db3be52 name:ZooKeeperConnection Watcher:127.0.0.1:52526 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1379854 T4224 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1379854 T4224 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 1379859 T4224 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4] 2> 1379862 T4224 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4] 2> 1379870 T4224 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4] 2> 1379874 T4224 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 1379882 T4224 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1379884 T4237 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@2cbd8ffd name:ZooKeeperConnection Watcher:127.0.0.1:52526/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1379884 T4224 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1379886 T4224 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 1379890 T4224 oascc.SolrZkClient.makePath makePath: /live_nodes/node1
[junit4] 2> 1379894 T4231 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 1379899 T4237 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 1379900 T4224 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1379901 T4239 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@5dce85a6 name:ZooKeeperConnection Watcher:127.0.0.1:52526/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1379901 T4224 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1379903 T4224 oascc.SolrZkClient.makePath makePath: /overseer_elect
[junit4] 2> 1379906 T4224 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4] 2> 1379913 T4224 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:52526_solr
[junit4] 2> 1379913 T4224 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 1379917 T4224 oasc.Overseer.start Overseer (id=91257849066356740-127.0.0.1:52526_solr-n_0000000000) starting
[junit4] 2> 1379920 T4224 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4] 2> 1379926 T4224 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4] 2> 1379935 T4224 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4] 2> 1379939 T4241 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 1379944 T4240 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 1379945 T4241 oasc.OverseerCollectionProcessor.prioritizeOverseerNodes prioritizing overseer nodes
[junit4] 2> 1379950 T4240 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1379951 T4240 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> 1379951 T4240 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1]
[junit4] 2> 1379951 T4240 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 1379955 T4239 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1379956 T4231 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> 1379956 T4237 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> 1380443 T4224 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 1380461 T4224 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 1380470 T4239 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1380472 T4224 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1380474 T4240 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1380481 T4231 oascc.ZkStateReader$3.process Updating live nodes... (0)
[junit4] 2> 1380484 T4239 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1380486 T4237 oascc.ZkStateReader$3.process Updating live nodes... (0)
[junit4] 2> 1380488 T4224 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1380490 T4243 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@c9c3a44 name:ZooKeeperConnection Watcher:127.0.0.1:52526/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1380490 T4224 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1380492 T4224 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 1380497 T4224 oascc.SolrZkClient.makePath makePath: /live_nodes/node1
[junit4] 2> 1380502 T4231 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 1380506 T4239 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1380507 T4224 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 1380508 T4243 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 1380514 T4240 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> 1380515 T4240 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 1380524 T4239 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1380528 T4224 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 1380535 T4239 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1380543 T4239 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1380648 T4243 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> 1380648 T4231 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> 1380652 T4224 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1380657 T4243 oascc.ZkStateReader$3.process Updating live nodes... (0)
[junit4] 2> 1380658 T4231 oascc.ZkStateReader$3.process Updating live nodes... (0)
[junit4] 2> 1380662 T4224 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:52526 52526
[junit4] 2> 1380803 T4224 oas.SolrTestCaseJ4.tearDown ###Ending testDoubleAssignment
[junit4] 1> client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 1380809 T4224 oas.SolrTestCaseJ4.setUp ###Starting testShardLeaderChange
[junit4] 2> 1380810 T4224 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4] 2> 1380810 T4244 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4] 2> 1380910 T4224 oasc.ZkTestServer.run start zk server on port:59485
[junit4] 2> 1380914 T4224 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1380926 T4250 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1647ac4d name:ZooKeeperConnection Watcher:127.0.0.1:59485/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1380926 T4224 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1380931 T4224 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1380932 T4252 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@45cc3219 name:ZooKeeperConnection Watcher:127.0.0.1:59485 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1380932 T4224 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1380965 T4224 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1380966 T4254 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@60e71453 name:ZooKeeperConnection Watcher:127.0.0.1:59485 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1380967 T4224 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1380967 T4224 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 1380973 T4224 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4] 2> 1380995 T4255 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1380995 T4258 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@46066792 name:ZooKeeperConnection Watcher:127.0.0.1:59485/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1380995 T4255 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1380996 T4224 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1380996 T4255 oascc.SolrZkClient.makePath makePath: /overseer_elect
[junit4] 2> 1380997 T4259 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@490ea4d name:ZooKeeperConnection Watcher:127.0.0.1:59485/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1380997 T4224 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1380999 T4224 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4] 2> 1381003 T4255 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4] 2> 1381006 T4224 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4] 2> 1381011 T4224 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 1381014 T4255 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:59485_solr
[junit4] 2> 1381014 T4255 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 1381019 T4255 oasc.Overseer.start Overseer (id=91257849141133315-127.0.0.1:59485_solr-n_0000000000) starting
[junit4] 2> 1381023 T4224 oascc.SolrZkClient.makePath makePath: /live_nodes/node1
[junit4] 2> 1381027 T4259 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 1381028 T4255 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4] 2> 1381035 T4255 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4] 2> 1381041 T4255 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4] 2> 1381045 T4255 oasc.OverseerTest$OverseerRestarter.run Killing overseer.
[junit4] 2> 1381045 T4261 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 1381048 T4255 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1381049 T4263 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@c83fc76 name:ZooKeeperConnection Watcher:127.0.0.1:59485/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1381049 T4255 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1381054 T4255 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:59485_solr
[junit4] 2> 1381054 T4255 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 1381058 T4255 oasc.Overseer.start Overseer (id=91257849141133317-127.0.0.1:59485_solr-n_0000000001) starting
[junit4] 2> 1381064 T4265 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 1381065 T4264 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 1381068 T4265 oasc.OverseerCollectionProcessor.prioritizeOverseerNodes prioritizing overseer nodes
[junit4] 2> 1381069 T4264 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1381070 T4264 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> 1381070 T4264 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1]
[junit4] 2> 1381071 T4264 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 1381074 T4263 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1381075 T4259 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> 1381533 T4224 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 1381551 T4224 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 1381560 T4263 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1381564 T4264 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1381568 T4263 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1381568 T4224 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 1381572 T4264 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> 1381572 T4264 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 1381578 T4263 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1381581 T4224 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1381583 T4267 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@5c1e640b name:ZooKeeperConnection Watcher:127.0.0.1:59485/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1381583 T4224 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1381585 T4224 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 1381588 T4224 oascc.SolrZkClient.makePath makePath: /live_nodes/node2
[junit4] 2> 1381594 T4259 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 1381598 T4263 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1381599 T4224 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 1381602 T4264 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> 1381602 T4264 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 1381606 T4263 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1381608 T4267 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 1381615 T4224 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1381711 T4259 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> 1381712 T4267 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> 1381818 T4224 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1381822 T4263 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1381822 T4263 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1381823 T4263 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1381826 T4264 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1381827 T4264 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> 1381827 T4264 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=1
[junit4] 2> 1381827 T4264 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 1381831 T4263 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1381935 T4259 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> 1381935 T4267 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> 1382323 T4224 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 1382334 T4267 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 1382334 T4259 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 1382337 T4224 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1382337 T4267 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 1382344 T4263 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1382344 T4263 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1382345 T4263 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1382346 T4264 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1382351 T4263 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1382454 T4267 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> 1382539 T4224 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1382541 T4224 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1382546 T4261 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:274)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:271)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.getData(SolrZkClient.java:271)
[junit4] 2> at org.apache.solr.cloud.OverseerCollectionProcessor.amILeader(OverseerCollectionProcessor.java:357)
[junit4] 2> at org.apache.solr.cloud.OverseerCollectionProcessor.run(OverseerCollectionProcessor.java:171)
[junit4] 2> at java.lang.Thread.run(Thread.java:662)
[junit4] 2>
[junit4] 2> 1382547 T4261 oasc.OverseerCollectionProcessor.amILeader According to ZK I (id=91257849141133315-127.0.0.1:59485_solr-n_0000000000) am no longer a leader.
[junit4] 2> 1382547 T4261 oasc.OverseerCollectionProcessor.prioritizeOverseerNodes prioritizing overseer nodes
[junit4] 2> 1382547 T4261 oasc.OverseerCollectionProcessor.run ERROR Unable to prioritize overseer org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /roles.json
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] 2> at org.apache.zookeeper.ZooKeeper.exists(ZooKeeper.java:1041)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$4.execute(SolrZkClient.java:223)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$4.execute(SolrZkClient.java:220)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.exists(SolrZkClient.java:220)
[junit4] 2> at org.apache.solr.cloud.OverseerCollectionProcessor.prioritizeOverseerNodes(OverseerCollectionProcessor.java:227)
[junit4] 2> at org.apache.solr.cloud.OverseerCollectionProcessor.run(OverseerCollectionProcessor.java:178)
[junit4] 2> at java.lang.Thread.run(Thread.java:662)
[junit4] 2>
[junit4] 2> 1382548 T4261 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:274)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:271)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.getData(SolrZkClient.java:271)
[junit4] 2> at org.apache.solr.cloud.OverseerCollectionProcessor.amILeader(OverseerCollectionProcessor.java:357)
[junit4] 2> at org.apache.solr.cloud.OverseerCollectionProcessor.run(OverseerCollectionProcessor.java:185)
[junit4] 2> at java.lang.Thread.run(Thread.java:662)
[junit4] 2>
[junit4] 2> 1382548 T4261 oasc.OverseerCollectionProcessor.amILeader According to ZK I (id=91257849141133315-127.0.0.1:59485_solr-n_0000000000) am no longer a leader.
[junit4] 2> 1382549 T4260 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:257)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:254)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.getChildren(SolrZkClient.java:254)
[junit4] 2> at org.apache.solr.cloud.DistributedQueue.orderedChildren(DistributedQueue.java:89)
[junit4] 2> at org.apache.solr.cloud.DistributedQueue.element(DistributedQueue.java:131)
[junit4] 2> at org.apache.solr.cloud.DistributedQueue.peek(DistributedQueue.java:325)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.run(Overseer.java:105)
[junit4] 2> at java.lang.Thread.run(Thread.java:662)
[junit4] 2>
[junit4] 2> 1382557 T4269 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@4f0d1c1b name:ZooKeeperConnection Watcher:127.0.0.1:59485/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1382557 T4224 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1382560 T4224 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 1382564 T4224 oascc.SolrZkClient.makePath makePath: /live_nodes/node1
[junit4] 2> 1382567 T4267 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 1382569 T4269 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 1382570 T4255 oasc.OverseerTest$OverseerRestarter.run Killing overseer.
[junit4] 2> 1382572 T4255 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1382574 T4271 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@7a2b3255 name:ZooKeeperConnection Watcher:127.0.0.1:59485/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1382574 T4255 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1382574 T4224 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 1382581 T4255 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:59485_solr
[junit4] 2> 1382582 T4255 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 1382588 T4255 oasc.Overseer.start Overseer (id=91257849141133320-127.0.0.1:59485_solr-n_0000000002) starting
[junit4] 2> 1382590 T4269 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 1382591 T4267 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 1382599 T4269 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 1382599 T4224 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 1382614 T4273 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 1382616 T4273 oasc.OverseerCollectionProcessor.prioritizeOverseerNodes prioritizing overseer nodes
[junit4] 2> 1382617 T4272 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 1382620 T4224 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1382621 T4275 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@398f1b41 name:ZooKeeperConnection Watcher:127.0.0.1:59485/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1382622 T4224 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1382623 T4272 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1382624 T4272 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> 1382624 T4272 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 1382625 T4224 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 1382630 T4271 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1382631 T4224 oascc.SolrZkClient.makePath makePath: /live_nodes/node2
[junit4] 2> 1382632 T4269 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> 1382632 T4275 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> 1382647 T4275 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 1382648 T4269 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 1382652 T4224 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 1382657 T4272 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1382658 T4272 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> 1382659 T4272 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 1382663 T4271 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1382666 T4224 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1382671 T4271 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1382673 T4272 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> 1382673 T4272 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 1382685 T4271 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1382789 T4275 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> 1382789 T4269 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> 1382869 T4224 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1382874 T4271 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1382874 T4271 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1382874 T4271 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1382874 T4224 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 1382877 T4272 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1382879 T4272 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> 1382879 T4272 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 1382884 T4271 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1382891 T4275 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 1382891 T4269 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 1382896 T4224 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1382904 T4275 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 1382912 T4271 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1382918 T4271 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1383022 T4275 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> 1383099 T4224 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1383100 T4224 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1383102 T4277 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@5ba27d00 name:ZooKeeperConnection Watcher:127.0.0.1:59485/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1383103 T4224 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1383104 T4224 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 1383108 T4224 oascc.SolrZkClient.makePath makePath: /live_nodes/node1
[junit4] 2> 1383113 T4275 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 1383114 T4277 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 1383114 T4255 oasc.OverseerTest$OverseerRestarter.run Killing overseer.
[junit4] 2> 1383116 T4255 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1383118 T4224 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 1383118 T4279 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@3ecb8cda name:ZooKeeperConnection Watcher:127.0.0.1:59485/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1383118 T4255 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1383138 T4255 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:59485_solr
[junit4] 2> 1383139 T4255 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 1383145 T4277 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 1383146 T4275 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 1383146 T4255 oasc.Overseer.start Overseer (id=91257849141133323-127.0.0.1:59485_solr-n_0000000003) starting
[junit4] 2> 1383151 T4277 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 1383154 T4224 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 1383157 T4281 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 1383159 T4281 oasc.OverseerCollectionProcessor.prioritizeOverseerNodes prioritizing overseer nodes
[junit4] 2> 1383160 T4280 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 1383167 T4280 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1383177 T4279 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1383186 T4280 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> 1383190 T4224 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1383190 T4280 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 1383194 T4283 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@63697147 name:ZooKeeperConnection Watcher:127.0.0.1:59485/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1383195 T4224 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1383197 T4224 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 1383199 T4277 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> 1383204 T4224 oascc.SolrZkClient.makePath makePath: /live_nodes/node2
[junit4] 2> 1383210 T4283 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 1383211 T4280 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1383211 T4277 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 1383212 T4280 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> 1383213 T4280 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 1383215 T4224 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 1383215 T4279 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1383240 T4279 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1383242 T4224 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1383243 T4280 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> 1383243 T4280 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 1383246 T4279 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1383350 T4283 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> 1383351 T4277 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> 1383444 T4224 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1383448 T4279 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1383449 T4224 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 1383449 T4279 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1383450 T4279 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1383452 T4280 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1383453 T4280 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> 1383454 T4280 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 1383461 T4279 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1383467 T4277 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 1383469 T4245 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x1443687c106000a, likely client has closed socket
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:220)
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208)
[junit4] 2> at java.lang.Thread.run(Thread.java:662)
[junit4] 2>
[junit4] 2> 1383470 T4224 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1383471 T4283 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 1383473 T4283 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 1383481 T4279 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1383488 T4279 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1383592 T4283 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> 1383673 T4224 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1383675 T4224 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1383677 T4285 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@70ee9434 name:ZooKeeperConnection Watcher:127.0.0.1:59485/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1383678 T4224 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1383680 T4224 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 1383684 T4224 oascc.SolrZkClient.makePath makePath: /live_nodes/node1
[junit4] 2> 1383688 T4283 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 1383689 T4285 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 1383692 T4279 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1383692 T4224 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 1383692 T4279 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1383693 T4279 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1383696 T4280 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1383697 T4280 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> 1383698 T4280 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 1383707 T4279 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1383713 T4285 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 1383713 T4283 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 1383716 T4285 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 1383717 T4279 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1383717 T4224 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 1383720 T4280 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> 1383720 T4280 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 1383725 T4279 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1383735 T4279 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1383745 T4279 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1383748 T4224 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1383750 T4287 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@72efe7b1 name:ZooKeeperConnection Watcher:127.0.0.1:59485/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1383750 T4224 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1383752 T4224 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 1383755 T4224 oascc.SolrZkClient.makePath makePath: /live_nodes/node2
[junit4] 2> 1383758 T4255 oasc.OverseerTest$OverseerRestarter.run Killing overseer.
[junit4] 2> 1383760 T4285 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 1383761 T4255 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1383761 T4287 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 1383762 T4289 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@39a4345c name:ZooKeeperConnection Watcher:127.0.0.1:59485/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1383762 T4255 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1383765 T4224 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 1383769 T4255 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:59485_solr
[junit4] 2> 1383769 T4255 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 1383780 T4224 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1383795 T4255 oasc.Overseer.start Overseer (id=91257849141133327-127.0.0.1:59485_solr-n_0000000004) starting
[junit4] 2> 1383801 T4291 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 1383803 T4291 oasc.OverseerCollectionProcessor.prioritizeOverseerNodes prioritizing overseer nodes
[junit4] 2> 1383805 T4290 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1383806 T4290 oasc.Overseer$ClusterStateUpdater.run Replaying operations from work queue.
[junit4] 2> 1383807 T4290 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> 1383807 T4290 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 1383808 T4285 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> 1383808 T4287 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> 1383815 T4290 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> 1383815 T4290 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 1383818 T4287 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> 1383818 T4285 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> 1383826 T4285 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> 1383826 T4287 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> 1383831 T4290 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 1383834 T4290 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1383835 T4290 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> 1383835 T4259 oasc.LeaderElector$1.process WARN org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /collections/collection1/leader_elect/shard1/election
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] 2> at org.apache.zookeeper.ZooKeeper.getChildren(ZooKeeper.java:1468)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:257)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:254)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.getChildren(SolrZkClient.java:254)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:92)
[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:137)
[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> 1383835 T4290 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 1383836 T4259 oasc.LeaderElector$1.process WARN org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /collections/collection1/leader_elect/shard1/election
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] 2> at org.apache.zookeeper.ZooKeeper.getChildren(ZooKeeper.java:1468)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:257)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:254)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.getChildren(SolrZkClient.java:254)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:92)
[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:137)
[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> 1383839 T4289 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1383841 T4287 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> 1383841 T4285 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> 1383846 T4280 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:257)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:254)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.getChildren(SolrZkClient.java:254)
[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:195)
[junit4] 2> at java.lang.Thread.run(Thread.java:662)
[junit4] 2>
[junit4] 2> 1383995 T4224 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1384000 T4289 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1384000 T4224 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 1384005 T4290 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1384006 T4290 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> 1384007 T4290 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 1384012 T4289 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1384017 T4287 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 1384018 T4285 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 1384020 T4224 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1384021 T4287 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 1384031 T4289 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1384036 T4289 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1384139 T4287 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> 1384223 T4224 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1384224 T4224 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1384226 T4293 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1a5a3c10 name:ZooKeeperConnection Watcher:127.0.0.1:59485/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1384226 T4224 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1384228 T4224 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 1384233 T4224 oascc.SolrZkClient.makePath makePath: /live_nodes/node1
[junit4] 2> 1384238 T4287 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 1384238 T4293 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 1384242 T4224 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 1384243 T4289 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1384243 T4289 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1384244 T4289 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1384257 T4290 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1384258 T4290 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> 1384258 T4290 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 1384260 T4293 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 1384261 T4287 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 1384264 T4289 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1384267 T4293 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 1384267 T4289 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1384267 T4224 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 1384269 T4290 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> 1384270 T4290 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 1384275 T4289 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1384279 T4289 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1384282 T4224 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1384283 T4295 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@335f3434 name:ZooKeeperConnection Watcher:127.0.0.1:59485/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1384284 T4224 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1384287 T4289 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1384288 T4224 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 1384293 T4224 oascc.SolrZkClient.makePath makePath: /live_nodes/node2
[junit4] 2> 1384297 T4295 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 1384298 T4293 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 1384301 T4289 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1384301 T4224 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 1384302 T4255 oasc.OverseerTest$OverseerRestarter.run Killing overseer.
[junit4] 2> 1384311 T4255 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1384312 T4297 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@5537a615 name:ZooKeeperConnection Watcher:127.0.0.1:59485/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1384312 T4255 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1384314 T4224 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1384317 T4255 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:59485_solr
[junit4] 2> 1384317 T4255 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 1384321 T4255 oasc.Overseer.start Overseer (id=91257849141133330-127.0.0.1:59485_solr-n_0000000005) starting
[junit4] 2> 1384328 T4299 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 1384329 T4299 oasc.OverseerCollectionProcessor.prioritizeOverseerNodes prioritizing overseer nodes
[junit4] 2> 1384334 T4298 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1384336 T4298 oasc.Overseer$ClusterStateUpdater.run Replaying operations from work queue.
[junit4] 2> 1384337 T4298 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> 1384337 T4298 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 1384339 T4293 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> 1384339 T4295 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> 1384346 T4298 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> 1384346 T4298 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 1384347 T4293 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> 1384350 T4295 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> 1384356 T4295 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> 1384356 T4293 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> 1384361 T4298 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 1384364 T4298 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1384365 T4298 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> 1384365 T4298 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 1384369 T4297 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1384370 T4295 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> 1384370 T4293 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> 1384393 T4269 oasc.LeaderElector$1.process WARN org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /collections/collection1/leader_elect/shard1/election
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] 2> at org.apache.zookeeper.ZooKeeper.getChildren(ZooKeeper.java:1468)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:257)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:254)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.getChildren(SolrZkClient.java:254)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:92)
[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:137)
[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> 1384393 T4269 oasc.LeaderElector$1.process WARN org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /collections/collection1/leader_elect/shard1/election
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] 2> at org.apache.zookeeper.ZooKeeper.getChildren(ZooKeeper.java:1468)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:257)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:254)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.getChildren(SolrZkClient.java:254)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:92)
[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:137)
[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> 1384516 T4224 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1384520 T4297 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1384520 T4224 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 1384525 T4298 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1384526 T4298 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> 1384526 T4298 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 1384532 T4297 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1384537 T4295 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 1384537 T4293 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 1384539 T4224 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1384542 T4295 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 1384551 T4297 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1384556 T4297 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1384659 T4295 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> 1384742 T4224 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1384744 T4224 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1384745 T4301 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@6225f2d0 name:ZooKeeperConnection Watcher:127.0.0.1:59485/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1384745 T4224 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1384747 T4224 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 1384751 T4224 oascc.SolrZkClient.makePath makePath: /live_nodes/node1
[junit4] 2> 1384755 T4295 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 1384757 T4301 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 1384760 T4297 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1384760 T4224 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 1384760 T4297 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1384760 T4297 o
[...truncated too long message...]
T4224 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4] 2> 1412767 T4224 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4] 2> 1412771 T4765 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 1412773 T4765 oasc.OverseerCollectionProcessor.prioritizeOverseerNodes prioritizing overseer nodes
[junit4] 2> 1412774 T4764 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 1412777 T4764 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1412778 T4764 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=12 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"recovering",
[junit4] 2> "node_name":"node1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"12",
[junit4] 2> "base_url":"http://node1/solr/"}
[junit4] 2> 1412778 T4764 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1, shard2, shard3, shard4, shard5, shard6, shard7, shard8, shard9, shard10, shard11, shard12]
[junit4] 2> 1412778 T4764 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 1412781 T4763 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1412783 T4761 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> 1412783 T4755 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> 1412952 T4568 oasc.LeaderElector$1.process WARN org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /collections/collection1/leader_elect/shard6/election
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] 2> at org.apache.zookeeper.ZooKeeper.getChildren(ZooKeeper.java:1468)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:257)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:254)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.getChildren(SolrZkClient.java:254)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:92)
[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:137)
[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> 1413275 T4224 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 1413288 T4224 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 1413296 T4763 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1413297 T4224 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1413299 T4764 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1413302 T4755 oascc.ZkStateReader$3.process Updating live nodes... (0)
[junit4] 2> 1413302 T4761 oascc.ZkStateReader$3.process Updating live nodes... (0)
[junit4] 2> 1413305 T4224 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:53076 53076
[junit4] 2> 1413427 T4224 oas.SolrTestCaseJ4.tearDown ###Ending testPlaceholders
[junit4] 1> client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 1413429 T4224 oas.SolrTestCaseJ4.initCore ####initCore
[junit4] 2> 1413430 T4224 oas.SolrTestCaseJ4.initCore ####initCore end
[junit4] 2> 1413791 T4642 oasc.LeaderElector$1.process WARN org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /collections/collection1/leaders/shard10
[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:429)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:426)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:383)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:370)
[junit4] 2> at org.apache.solr.cloud.ShardLeaderElectionContextBase.runLeaderProcess(ElectionContext.java:112)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.runIamLeaderProcess(LeaderElector.java:164)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:108)
[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:137)
[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> 1413792 T4642 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4] 2> 1416430 T4224 oas.SolrTestCaseJ4.deleteCore ###deleteCore
[junit4] 2> NOTE: test params are: codec=Lucene46: {}, docValues:{}, sim=RandomSimilarityProvider(queryNorm=true,coord=crazy): {}, locale=is, timezone=America/Coral_Harbour
[junit4] 2> NOTE: Linux 3.8.0-35-generic amd64/Sun Microsystems Inc. 1.6.0_45 (64-bit)/cpus=8,threads=1,free=151866944,total=491405312
[junit4] 2> NOTE: All tests run in this JVM: [BJQParserTest, TestReplicationHandler, ParsingFieldUpdateProcessorsTest, ScriptEngineTest, SolrXmlInZkTest, ShardSplitTest, LeaderElectionTest, TestSolrXmlPersistor, BinaryUpdateRequestHandlerTest, BlockCacheTest, SampleTest, TestPHPSerializedResponseWriter, DeleteShardTest, TermVectorComponentTest, TestFunctionQuery, DateMathParserTest, TestRemoteStreaming, TestFieldTypeCollectionResource, ReturnFieldsTest, FastVectorHighlighterTest, UUIDFieldTest, DistribCursorPagingTest, ShardRoutingTest, EnumFieldTest, TestFaceting, ZkControllerTest, TestAnalyzeInfixSuggestions, TestLRUCache, SliceStateTest, QueryElevationComponentTest, TestRandomDVFaceting, IndexSchemaTest, DocumentBuilderTest, MigrateRouteKeyTest, TestGroupingSearch, TestSchemaVersionResource, HdfsBasicDistributedZkTest, SynonymTokenizerTest, DirectUpdateHandlerOptimizeTest, PeerSyncTest, TestSuggestSpellingConverter, SuggestComponentTest, TestLMDirichletSimilarityFactory, TriLevelCompositeIdRoutingTest, SOLR749Test, TestPostingsSolrHighlighter, TestCustomSort, ZkCLITest, TestDocBasedVersionConstraints, PolyFieldTest, ExternalFileFieldSortTest, TestSolrQueryParser, CustomCollectionTest, TestHighFrequencyDictionaryFactory, SpatialFilterTest, AnalysisErrorHandlingTest, TestSolrIndexConfig, SolrTestCaseJ4Test, CircularListTest, HdfsCollectionsAPIDistributedZkTest, TestExtendedDismaxParser, UnloadDistributedZkTest, SearchHandlerTest, TestNRTOpen, TestNoOpRegenerator, CacheHeaderTest, TestDynamicFieldCollectionResource, TestWriterPerf, TestSearchPerf, UpdateParamsTest, URLClassifyProcessorTest, BasicDistributedZkTest, TestCoreContainer, SchemaVersionSpecificBehaviorTest, TestElisionMultitermQuery, SystemInfoHandlerTest, TestFieldCollectionResource, TestSolrDeletionPolicy1, SolrInfoMBeanTest, OverseerTest]
[junit4] Completed on J0 in 36.80s, 8 tests, 1 error <<< FAILURES!
[...truncated 501 lines...]
BUILD FAILED
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/build.xml:459: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/build.xml:439: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/build.xml:39: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/extra-targets.xml:37: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build.xml:189: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/common-build.xml:491: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/lucene/common-build.xml:1308: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/lucene/common-build.xml:941: There were test failures: 362 suites, 1563 tests, 1 error, 35 ignored (7 assumptions)
Total time: 53 minutes 31 seconds
Build step 'Invoke Ant' marked build as failure
Description set: Java: 64bit/jdk1.6.0_45 -XX:+UseCompressedOops -XX:+UseConcMarkSweepGC
Archiving artifacts
Recording test results
Email was triggered for: Failure
Sending email for trigger: Failure