aboutsummaryrefslogtreecommitdiff
diff options
context:
space:
mode:
authorbors[bot] <bors[bot]@users.noreply.github.com>2019-05-29 12:59:38 +0100
committerbors[bot] <bors[bot]@users.noreply.github.com>2019-05-29 12:59:38 +0100
commit87c8437af32779e1fd42d94b4c4147f6dd2b8157 (patch)
treefa95043e19fdd2390f5c4ce73a5be05e6b1ea8ae
parent9eef546ca2f59d0ebc0e5dc443fc1a5d93926030 (diff)
parente45c350a3b0ec5b25c23c334e09eba2901adbcd4 (diff)
Merge #1341
1341: log the actual time of requests r=matklad a=matklad Co-authored-by: Aleksey Kladov <[email protected]>
-rw-r--r--crates/ra_lsp_server/src/main_loop.rs61
1 files changed, 42 insertions, 19 deletions
diff --git a/crates/ra_lsp_server/src/main_loop.rs b/crates/ra_lsp_server/src/main_loop.rs
index 87b4e3ac2..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,7 +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 state.maybe_collect_garbage();
174 log::trace!("selecting"); 173 log::trace!("selecting");
175 let event = select! { 174 let event = select! {
176 recv(msg_receiver) -> msg => match msg { 175 recv(msg_receiver) -> msg => match msg {
@@ -184,17 +183,28 @@ fn main_loop_inner(
184 }, 183 },
185 recv(libdata_receiver) -> data => Event::Lib(data.unwrap()) 184 recv(libdata_receiver) -> data => Event::Lib(data.unwrap())
186 }; 185 };
187 log::info!("loop_turn = {:?}", event); 186 // NOTE: don't count blocking select! call as a loop-turn time
188 let _p = profile("loop_turn"); 187 let _p = profile("main_loop_inner/loop-turn");
188 let loop_start = Instant::now();
189
190 log::info!("loop turn = {:?}", event);
191 let queue_count = pool.queued_count();
192 if queue_count > 0 {
193 log::info!("queued count = {}", queue_count);
194 }
189 let mut state_changed = false; 195 let mut state_changed = false;
190 match event { 196 match event {
191 Event::Task(task) => on_task(task, msg_sender, pending_requests), 197 Event::Task(task) => {
198 on_task(task, msg_sender, pending_requests);
199 state.maybe_collect_garbage();
200 }
192 Event::Vfs(task) => { 201 Event::Vfs(task) => {
193 state.vfs.write().handle_task(task); 202 state.vfs.write().handle_task(task);
194 state_changed = true; 203 state_changed = true;
195 } 204 }
196 Event::Lib(lib) => { 205 Event::Lib(lib) => {
197 state.add_lib(lib); 206 state.add_lib(lib);
207 state.maybe_collect_garbage();
198 in_flight_libraries -= 1; 208 in_flight_libraries -= 1;
199 } 209 }
200 Event::Msg(msg) => match msg { 210 Event::Msg(msg) => match msg {
@@ -210,7 +220,14 @@ fn main_loop_inner(
210 msg_sender.send(resp.into()).unwrap() 220 msg_sender.send(resp.into()).unwrap()
211 } 221 }
212 Err(req) => { 222 Err(req) => {
213 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 )? {
214 None => (), 231 None => (),
215 Some(req) => { 232 Some(req) => {
216 log::error!("unknown request: {:?}", req); 233 log::error!("unknown request: {:?}", req);
@@ -272,10 +289,15 @@ fn main_loop_inner(
272 } 289 }
273} 290}
274 291
275fn 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) {
276 match task { 297 match task {
277 Task::Respond(response) => { 298 Task::Respond(response) => {
278 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());
279 msg_sender.send(response.into()).unwrap(); 301 msg_sender.send(response.into()).unwrap();
280 } 302 }
281 } 303 }
@@ -287,9 +309,10 @@ fn on_task(task: Task, msg_sender: &Sender<RawMessage>, pending_requests: &mut F
287 309
288fn on_request( 310fn on_request(
289 world: &mut ServerWorldState, 311 world: &mut ServerWorldState,
290 pending_requests: &mut FxHashSet<u64>, 312 pending_requests: &mut FxHashMap<u64, Instant>,
291 pool: &ThreadPool, 313 pool: &ThreadPool,
292 sender: &Sender<Task>, 314 sender: &Sender<Task>,
315 request_received: Instant,
293 req: RawRequest, 316 req: RawRequest,
294) -> Result<Option<RawRequest>> { 317) -> Result<Option<RawRequest>> {
295 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 };
@@ -325,8 +348,8 @@ fn on_request(
325 .finish(); 348 .finish();
326 match req { 349 match req {
327 Ok(id) => { 350 Ok(id) => {
328 let inserted = pending_requests.insert(id); 351 let prev = pending_requests.insert(id, request_received);
329 assert!(inserted, "duplicate request: {}", id); 352 assert!(prev.is_none(), "duplicate request: {}", id);
330 Ok(None) 353 Ok(None)
331 } 354 }
332 Err(req) => Ok(Some(req)), 355 Err(req) => Ok(Some(req)),
@@ -336,7 +359,7 @@ fn on_request(
336fn on_notification( 359fn on_notification(
337 msg_sender: &Sender<RawMessage>, 360 msg_sender: &Sender<RawMessage>,
338 state: &mut ServerWorldState, 361 state: &mut ServerWorldState,
339 pending_requests: &mut FxHashSet<u64>, 362 pending_requests: &mut FxHashMap<u64, Instant>,
340 subs: &mut Subscriptions, 363 subs: &mut Subscriptions,
341 not: RawNotification, 364 not: RawNotification,
342) -> Result<()> { 365) -> Result<()> {
@@ -348,7 +371,7 @@ fn on_notification(
348 panic!("string id's not supported: {:?}", id); 371 panic!("string id's not supported: {:?}", id);
349 } 372 }
350 }; 373 };
351 if pending_requests.remove(&id) { 374 if pending_requests.remove(&id).is_some() {
352 let response = RawResponse::err( 375 let response = RawResponse::err(
353 id, 376 id,
354 ErrorCode::RequestCanceled as i32, 377 ErrorCode::RequestCanceled as i32,
@@ -426,7 +449,7 @@ impl<'a> PoolDispatcher<'a> {
426 let world = self.world.snapshot(); 449 let world = self.world.snapshot();
427 let sender = self.sender.clone(); 450 let sender = self.sender.clone();
428 self.pool.execute(move || { 451 self.pool.execute(move || {
429 let resp = match f(world, params) { 452 let response = match f(world, params) {
430 Ok(resp) => RawResponse::ok::<R>(id, &resp), 453 Ok(resp) => RawResponse::ok::<R>(id, &resp),
431 Err(e) => match e.downcast::<LspError>() { 454 Err(e) => match e.downcast::<LspError>() {
432 Ok(lsp_error) => { 455 Ok(lsp_error) => {
@@ -458,7 +481,7 @@ impl<'a> PoolDispatcher<'a> {
458 } 481 }
459 }, 482 },
460 }; 483 };
461 let task = Task::Respond(resp); 484 let task = Task::Respond(response);
462 sender.send(task).unwrap(); 485 sender.send(task).unwrap();
463 }); 486 });
464 self.res = Some(id); 487 self.res = Some(id);
@@ -468,7 +491,7 @@ impl<'a> PoolDispatcher<'a> {
468 Ok(self) 491 Ok(self)
469 } 492 }
470 493
471 fn finish(&mut self) -> ::std::result::Result<u64, RawRequest> { 494 fn finish(&mut self) -> std::result::Result<u64, RawRequest> {
472 match (self.res.take(), self.req.take()) { 495 match (self.res.take(), self.req.take()) {
473 (Some(res), None) => Ok(res), 496 (Some(res), None) => Ok(res),
474 (None, Some(req)) => Err(req), 497 (None, Some(req)) => Err(req),