aboutsummaryrefslogtreecommitdiff
diff options
context:
space:
mode:
authorAleksey Kladov <[email protected]>2019-05-29 12:59:01 +0100
committerAleksey Kladov <[email protected]>2019-05-29 12:59:01 +0100
commite45c350a3b0ec5b25c23c334e09eba2901adbcd4 (patch)
treefa95043e19fdd2390f5c4ce73a5be05e6b1ea8ae
parent118a2113c148ce6806732094c70fb030139b26ac (diff)
log the actual time of requests
-rw-r--r--crates/ra_lsp_server/src/main_loop.rs47
1 files changed, 31 insertions, 16 deletions
diff --git a/crates/ra_lsp_server/src/main_loop.rs b/crates/ra_lsp_server/src/main_loop.rs
index d406faf6c..c3580ab67 100644
--- a/crates/ra_lsp_server/src/main_loop.rs
+++ b/crates/ra_lsp_server/src/main_loop.rs
@@ -1,7 +1,7 @@
1mod handlers; 1mod handlers;
2mod subscriptions; 2mod subscriptions;
3 3
4use std::{fmt, path::PathBuf, sync::Arc}; 4use std::{fmt, path::PathBuf, sync::Arc, time::Instant};
5 5
6use crossbeam_channel::{select, unbounded, Receiver, RecvError, Sender}; 6use crossbeam_channel::{select, unbounded, Receiver, RecvError, Sender};
7use failure::{bail, format_err}; 7use failure::{bail, format_err};
@@ -12,7 +12,7 @@ use gen_lsp_server::{
12use lsp_types::NumberOrString; 12use lsp_types::NumberOrString;
13use ra_ide_api::{Canceled, FileId, LibraryData}; 13use ra_ide_api::{Canceled, FileId, LibraryData};
14use ra_vfs::VfsTask; 14use ra_vfs::VfsTask;
15use rustc_hash::FxHashSet; 15use rustc_hash::FxHashMap;
16use serde::{de::DeserializeOwned, Serialize}; 16use serde::{de::DeserializeOwned, Serialize};
17use threadpool::ThreadPool; 17use threadpool::ThreadPool;
18 18
@@ -82,7 +82,7 @@ pub fn main_loop(
82 82
83 log::info!("server initialized, serving requests"); 83 log::info!("server initialized, serving requests");
84 84
85 let mut pending_requests = FxHashSet::default(); 85 let mut pending_requests = FxHashMap::default();
86 let mut subs = Subscriptions::new(); 86 let mut subs = Subscriptions::new();
87 let main_res = main_loop_inner( 87 let main_res = main_loop_inner(
88 options, 88 options,
@@ -159,7 +159,7 @@ fn main_loop_inner(
159 task_sender: Sender<Task>, 159 task_sender: Sender<Task>,
160 task_receiver: Receiver<Task>, 160 task_receiver: Receiver<Task>,
161 state: &mut ServerWorldState, 161 state: &mut ServerWorldState,
162 pending_requests: &mut FxHashSet<u64>, 162 pending_requests: &mut FxHashMap<u64, Instant>,
163 subs: &mut Subscriptions, 163 subs: &mut Subscriptions,
164) -> Result<()> { 164) -> Result<()> {
165 // We try not to index more than THREADPOOL_SIZE - 3 libraries at the same 165 // We try not to index more than THREADPOOL_SIZE - 3 libraries at the same
@@ -170,8 +170,6 @@ fn main_loop_inner(
170 170
171 let (libdata_sender, libdata_receiver) = unbounded(); 171 let (libdata_sender, libdata_receiver) = unbounded();
172 loop { 172 loop {
173 let _p = profile("loop_turn");
174
175 log::trace!("selecting"); 173 log::trace!("selecting");
176 let event = select! { 174 let event = select! {
177 recv(msg_receiver) -> msg => match msg { 175 recv(msg_receiver) -> msg => match msg {
@@ -185,6 +183,10 @@ fn main_loop_inner(
185 }, 183 },
186 recv(libdata_receiver) -> data => Event::Lib(data.unwrap()) 184 recv(libdata_receiver) -> data => Event::Lib(data.unwrap())
187 }; 185 };
186 // NOTE: don't count blocking select! call as a loop-turn time
187 let _p = profile("main_loop_inner/loop-turn");
188 let loop_start = Instant::now();
189
188 log::info!("loop turn = {:?}", event); 190 log::info!("loop turn = {:?}", event);
189 let queue_count = pool.queued_count(); 191 let queue_count = pool.queued_count();
190 if queue_count > 0 { 192 if queue_count > 0 {
@@ -218,7 +220,14 @@ fn main_loop_inner(
218 msg_sender.send(resp.into()).unwrap() 220 msg_sender.send(resp.into()).unwrap()
219 } 221 }
220 Err(req) => { 222 Err(req) => {
221 match on_request(state, pending_requests, pool, &task_sender, req)? { 223 match on_request(
224 state,
225 pending_requests,
226 pool,
227 &task_sender,
228 loop_start,
229 req,
230 )? {
222 None => (), 231 None => (),
223 Some(req) => { 232 Some(req) => {
224 log::error!("unknown request: {:?}", req); 233 log::error!("unknown request: {:?}", req);
@@ -280,10 +289,15 @@ fn main_loop_inner(
280 } 289 }
281} 290}
282 291
283fn on_task(task: Task, msg_sender: &Sender<RawMessage>, pending_requests: &mut FxHashSet<u64>) { 292fn on_task(
293 task: Task,
294 msg_sender: &Sender<RawMessage>,
295 pending_requests: &mut FxHashMap<u64, Instant>,
296) {
284 match task { 297 match task {
285 Task::Respond(response) => { 298 Task::Respond(response) => {
286 if pending_requests.remove(&response.id) { 299 if let Some(request_received) = pending_requests.remove(&response.id) {
300 log::info!("handled req#{} in {:?}", response.id, request_received.elapsed());
287 msg_sender.send(response.into()).unwrap(); 301 msg_sender.send(response.into()).unwrap();
288 } 302 }
289 } 303 }
@@ -295,9 +309,10 @@ fn on_task(task: Task, msg_sender: &Sender<RawMessage>, pending_requests: &mut F
295 309
296fn on_request( 310fn on_request(
297 world: &mut ServerWorldState, 311 world: &mut ServerWorldState,
298 pending_requests: &mut FxHashSet<u64>, 312 pending_requests: &mut FxHashMap<u64, Instant>,
299 pool: &ThreadPool, 313 pool: &ThreadPool,
300 sender: &Sender<Task>, 314 sender: &Sender<Task>,
315 request_received: Instant,
301 req: RawRequest, 316 req: RawRequest,
302) -> Result<Option<RawRequest>> { 317) -> Result<Option<RawRequest>> {
303 let mut pool_dispatcher = PoolDispatcher { req: Some(req), res: None, pool, world, sender }; 318 let mut pool_dispatcher = PoolDispatcher { req: Some(req), res: None, pool, world, sender };
@@ -333,8 +348,8 @@ fn on_request(
333 .finish(); 348 .finish();
334 match req { 349 match req {
335 Ok(id) => { 350 Ok(id) => {
336 let inserted = pending_requests.insert(id); 351 let prev = pending_requests.insert(id, request_received);
337 assert!(inserted, "duplicate request: {}", id); 352 assert!(prev.is_none(), "duplicate request: {}", id);
338 Ok(None) 353 Ok(None)
339 } 354 }
340 Err(req) => Ok(Some(req)), 355 Err(req) => Ok(Some(req)),
@@ -344,7 +359,7 @@ fn on_request(
344fn on_notification( 359fn on_notification(
345 msg_sender: &Sender<RawMessage>, 360 msg_sender: &Sender<RawMessage>,
346 state: &mut ServerWorldState, 361 state: &mut ServerWorldState,
347 pending_requests: &mut FxHashSet<u64>, 362 pending_requests: &mut FxHashMap<u64, Instant>,
348 subs: &mut Subscriptions, 363 subs: &mut Subscriptions,
349 not: RawNotification, 364 not: RawNotification,
350) -> Result<()> { 365) -> Result<()> {
@@ -356,7 +371,7 @@ fn on_notification(
356 panic!("string id's not supported: {:?}", id); 371 panic!("string id's not supported: {:?}", id);
357 } 372 }
358 }; 373 };
359 if pending_requests.remove(&id) { 374 if pending_requests.remove(&id).is_some() {
360 let response = RawResponse::err( 375 let response = RawResponse::err(
361 id, 376 id,
362 ErrorCode::RequestCanceled as i32, 377 ErrorCode::RequestCanceled as i32,
@@ -434,7 +449,7 @@ impl<'a> PoolDispatcher<'a> {
434 let world = self.world.snapshot(); 449 let world = self.world.snapshot();
435 let sender = self.sender.clone(); 450 let sender = self.sender.clone();
436 self.pool.execute(move || { 451 self.pool.execute(move || {
437 let resp = match f(world, params) { 452 let response = match f(world, params) {
438 Ok(resp) => RawResponse::ok::<R>(id, &resp), 453 Ok(resp) => RawResponse::ok::<R>(id, &resp),
439 Err(e) => match e.downcast::<LspError>() { 454 Err(e) => match e.downcast::<LspError>() {
440 Ok(lsp_error) => { 455 Ok(lsp_error) => {
@@ -466,7 +481,7 @@ impl<'a> PoolDispatcher<'a> {
466 } 481 }
467 }, 482 },
468 }; 483 };
469 let task = Task::Respond(resp); 484 let task = Task::Respond(response);
470 sender.send(task).unwrap(); 485 sender.send(task).unwrap();
471 }); 486 });
472 self.res = Some(id); 487 self.res = Some(id);