Merge #5866

5866: Improve logging
 r=matklad a=matklad

bors r+
🤖

Co-authored-by: Aleksey Kladov <aleksey.kladov@gmail.com>

crates/project_model/src/lib.rs

@@ -6,6 +6,7 @@ mod sysroot;
 mod cfg_flag;
 
 use std::{
+    fmt,
     fs::{self, read_dir, ReadDir},
     io,
     process::Command,
@@ -27,7 +28,7 @@ pub use crate::{
 
 pub use proc_macro_api::ProcMacroClient;
 
-#[derive(Debug, Clone, Eq, PartialEq)]
+#[derive(Clone, Eq, PartialEq)]
 pub enum ProjectWorkspace {
     /// Project workspace was discovered by running `cargo metadata` and `rustc --print sysroot`.
     Cargo { cargo: CargoWorkspace, sysroot: Sysroot },
@@ -35,6 +36,19 @@ pub enum ProjectWorkspace {
     Json { project: ProjectJson },
 }
 
+impl fmt::Debug for ProjectWorkspace {
+    fn fmt(&self, f: &mut fmt::Formatter<'_>) -> fmt::Result {
+        match self {
+            ProjectWorkspace::Cargo { cargo, .. } => {
+                f.debug_struct("Cargo").field("n_packages", &cargo.packages().len()).finish()
+            }
+            ProjectWorkspace::Json { project } => {
+                f.debug_struct("Json").field("n_crates", &project.crates.len()).finish()
+            }
+        }
+    }
+}
+
 /// `PackageRoot` describes a package root folder.
 /// Which may be an external dependency, or a member of
 /// the current workspace.

crates/rust-analyzer/src/bin/main.rs

@@ -60,11 +60,12 @@ fn setup_logging() -> Result<()> {
 }
 
 fn run_server() -> Result<()> {
-    log::info!("lifecycle: server started");
+    log::info!("server will start");
 
     let (connection, io_threads) = Connection::stdio();
 
     let (initialize_id, initialize_params) = connection.initialize_start()?;
+    log::info!("InitializeParams: {}", initialize_params);
     let initialize_params =
         from_json::<lsp_types::InitializeParams>("InitializeParams", initialize_params)?;
 
@@ -118,10 +119,9 @@ fn run_server() -> Result<()> {
                 .filter(|workspaces| !workspaces.is_empty())
                 .unwrap_or_else(|| vec![config.root_path.clone()]);
 
-            config.linked_projects = ProjectManifest::discover_all(&workspace_roots)
-                .into_iter()
-                .map(LinkedProject::from)
-                .collect();
+            let discovered = ProjectManifest::discover_all(&workspace_roots);
+            log::info!("discovered projects: {:?}", discovered);
+            config.linked_projects = discovered.into_iter().map(LinkedProject::from).collect();
         }
 
         config
@@ -129,8 +129,7 @@ fn run_server() -> Result<()> {
 
     rust_analyzer::main_loop(config, connection)?;
 
-    log::info!("shutting down IO...");
     io_threads.join()?;
-    log::info!("... IO is down");
+    log::info!("server did shut down");
     Ok(())
 }

crates/rust-analyzer/src/main_loop.rs

@@ -10,6 +10,8 @@ use crossbeam_channel::{select, Receiver};
 use ide::{Canceled, FileId};
 use lsp_server::{Connection, Notification, Request, Response};
 use lsp_types::notification::Notification as _;
+use project_model::ProjectWorkspace;
+use vfs::ChangeKind;
 
 use crate::{
     config::Config,
@@ -21,8 +23,6 @@ use crate::{
     lsp_utils::{apply_document_changes, is_canceled, notification_is, Progress},
     Result,
 };
-use project_model::ProjectWorkspace;
-use vfs::ChangeKind;
 
 pub fn main_loop(config: Config, connection: Connection) -> Result<()> {
     log::info!("initial config: {:#?}", config);
@@ -175,9 +175,9 @@ impl GlobalState {
         let _p = profile::span("GlobalState::handle_event");
 
         log::info!("handle_event({:?})", event);
-        let queue_count = self.task_pool.handle.len();
-        if queue_count > 0 {
-            log::info!("queued count = {}", queue_count);
+        let task_queue_len = self.task_pool.handle.len();
+        if task_queue_len > 0 {
+            log::info!("task queue len: {}", task_queue_len);
         }
 
         let prev_status = self.status;

crates/rust-analyzer/src/reload.rs

@@ -92,6 +92,7 @@ impl GlobalState {
         }
     }
     pub(crate) fn fetch_workspaces(&mut self) {
+        log::info!("will fetch workspaces");
         self.task_pool.handle.spawn({
             let linked_projects = self.config.linked_projects.clone();
             let cargo_config = self.config.cargo.clone();
@@ -112,13 +113,14 @@ impl GlobalState {
                         }
                     })
                     .collect::<Vec<_>>();
+                log::info!("did fetch workspaces {:?}", workspaces);
                 Task::Workspaces(workspaces)
             }
         });
     }
     pub(crate) fn switch_workspaces(&mut self, workspaces: Vec<anyhow::Result<ProjectWorkspace>>) {
         let _p = profile::span("GlobalState::switch_workspaces");
-        log::info!("reloading projects: {:?}", self.config.linked_projects);
+        log::info!("will switch workspaces: {:?}", workspaces);
 
         let mut has_errors = false;
         let workspaces = workspaces
@@ -223,6 +225,7 @@ impl GlobalState {
         self.analysis_host.apply_change(change);
         self.process_changes();
         self.reload_flycheck();
+        log::info!("did switch workspaces");
     }
 
     fn reload_flycheck(&mut self) {

docs/user/manual.adoc

@@ -341,6 +341,8 @@ Relative paths are interpreted relative to `rust-project.json` file location or
 
 See https://github.com/rust-analyzer/rust-project.json-example for a small example.
 
+You can set `RA_LOG` environmental variable to `"'rust_analyzer=info"` to inspect how rust-analyzer handles config and project loading.
+
 == Features
 
 include::./generated_features.adoc[]