Merge #321

321: More useful logging r=matklad a=matklad

Try not to log *huge* messages, to make logging more useful.

Co-authored-by: Aleksey Kladov <[email protected]>

5 files changed, 62 insertions, 11 deletions

diff --git a/crates/gen_lsp_server/src/msg.rs b/crates/gen_lsp_server/src/msg.rs
index af901d0d2..f68cbc541 100644
--- a/crates/gen_lsp_server/src/msg.rs
+++ b/crates/gen_lsp_server/src/msg.rs
@@ -152,12 +152,18 @@ impl RawNotification {
             params: to_value(params).unwrap(),
         }
     }
+    pub fn is<N>(&self) -> bool
+    where
+        N: Notification,
+    {
+        self.method == N::METHOD
+    }
     pub fn cast<N>(self) -> ::std::result::Result<N::Params, RawNotification>
     where
         N: Notification,
         N::Params: serde::de::DeserializeOwned,
     {
-        if self.method != N::METHOD {
+        if !self.is::<N>() {
             return Err(self);
         }
         Ok(from_value(self.params).unwrap())
diff --git a/crates/ra_analysis/src/lib.rs b/crates/ra_analysis/src/lib.rs
index 6fd157880..85df9c089 100644
--- a/crates/ra_analysis/src/lib.rs
+++ b/crates/ra_analysis/src/lib.rs
@@ -368,13 +368,22 @@ impl Analysis {
     }
 }
 
-#[derive(Debug)]
 pub struct LibraryData {
     root_id: SourceRootId,
     root_change: RootChange,
     symbol_index: SymbolIndex,
 }
 
+impl fmt::Debug for LibraryData {
+    fn fmt(&self, f: &mut fmt::Formatter) -> fmt::Result {
+        f.debug_struct("LibraryData")
+            .field("root_id", &self.root_id)
+            .field("root_change", &self.root_change)
+            .field("n_symbols", &self.symbol_index.len())
+            .finish()
+    }
+}
+
 impl LibraryData {
     pub fn prepare(
         root_id: SourceRootId,
diff --git a/crates/ra_analysis/src/symbol_index.rs b/crates/ra_analysis/src/symbol_index.rs
index b48a37229..e5bdf0aa1 100644
--- a/crates/ra_analysis/src/symbol_index.rs
+++ b/crates/ra_analysis/src/symbol_index.rs
@@ -56,6 +56,10 @@ impl Hash for SymbolIndex {
 }
 
 impl SymbolIndex {
+    pub(crate) fn len(&self) -> usize {
+        self.symbols.len()
+    }
+
     pub(crate) fn for_files(
         files: impl ParallelIterator<Item = (FileId, SourceFileNode)>,
     ) -> SymbolIndex {
diff --git a/crates/ra_lsp_server/src/main_loop.rs b/crates/ra_lsp_server/src/main_loop.rs
index afe0fec89..84f88eeff 100644
--- a/crates/ra_lsp_server/src/main_loop.rs
+++ b/crates/ra_lsp_server/src/main_loop.rs
@@ -2,6 +2,7 @@ mod handlers;
 mod subscriptions;
 
 use std::{
+    fmt,
     path::PathBuf,
     sync::Arc,
 };
@@ -109,6 +110,43 @@ pub fn main_loop(
     Ok(())
 }
 
+enum Event {
+    Msg(RawMessage),
+    Task(Task),
+    Vfs(VfsTask),
+    Lib(LibraryData),
+}
+
+impl fmt::Debug for Event {
+    fn fmt(&self, f: &mut fmt::Formatter) -> fmt::Result {
+        let debug_verbose_not = |not: &RawNotification, f: &mut fmt::Formatter| {
+            f.debug_struct("RawNotification")
+                .field("method", &not.method)
+                .finish()
+        };
+
+        match self {
+            Event::Msg(RawMessage::Notification(not)) => {
+                if not.is::<req::DidOpenTextDocument>() || not.is::<req::DidChangeTextDocument>() {
+                    return debug_verbose_not(not, f);
+                }
+            }
+            Event::Task(Task::Notify(not)) => {
+                if not.is::<req::PublishDecorations>() || not.is::<req::PublishDiagnostics>() {
+                    return debug_verbose_not(not, f);
+                }
+            }
+            _ => (),
+        }
+        match self {
+            Event::Msg(it) => fmt::Debug::fmt(it, f),
+            Event::Task(it) => fmt::Debug::fmt(it, f),
+            Event::Vfs(it) => fmt::Debug::fmt(it, f),
+            Event::Lib(it) => fmt::Debug::fmt(it, f),
+        }
+    }
+}
+
 fn main_loop_inner(
     internal_mode: bool,
     publish_decorations: bool,
@@ -123,13 +161,6 @@ fn main_loop_inner(
 ) -> Result<()> {
     let (libdata_sender, libdata_receiver) = unbounded();
     loop {
-        #[derive(Debug)]
-        enum Event {
-            Msg(RawMessage),
-            Task(Task),
-            Vfs(VfsTask),
-            Lib(LibraryData),
-        }
         log::trace!("selecting");
         let event = select! {
             recv(msg_receiver, msg) => match msg {
@@ -143,7 +174,8 @@ fn main_loop_inner(
             }
             recv(libdata_receiver, data) => Event::Lib(data.unwrap())
         };
-        log::info!("{:?}", event);
+        log::info!("loop_turn = {:?}", event);
+        let start = std::time::Instant::now();
         let mut state_changed = false;
         match event {
             Event::Task(task) => on_task(task, msg_sender, pending_requests),
@@ -206,6 +238,7 @@ fn main_loop_inner(
                 subs.subscriptions(),
             )
         }
+        log::info!("loop_turn = {:?}", start.elapsed());
     }
 }
 
diff --git a/crates/ra_lsp_server/src/server_world.rs b/crates/ra_lsp_server/src/server_world.rs
index 73cccc9dd..c183c25af 100644
--- a/crates/ra_lsp_server/src/server_world.rs
+++ b/crates/ra_lsp_server/src/server_world.rs
@@ -107,7 +107,6 @@ impl ServerWorldState {
         let mut libs = Vec::new();
         let mut change = AnalysisChange::new();
         for c in changes {
-            log::info!("vfs change {:?}", c);
             match c {
                 VfsChange::AddRoot { root, files } => {
                     let root_path = self.vfs.read().root2path(root);