internal: add tracing to project discovery and VFS loading

Author: davidbarsky

crates/rust-analyzer/src/discover.rs

@@ -7,6 +7,7 @@ use paths::{AbsPathBuf, Utf8Path, Utf8PathBuf};
 use project_model::ProjectJsonData;
 use serde::{Deserialize, Serialize};
 use serde_json::Value;
+use tracing::{info_span, span::EnteredSpan};
 
 use crate::command::{CommandHandle, ParseFromLine};
 
@@ -60,14 +61,19 @@ impl DiscoverCommand {
         let mut cmd = Command::new(command);
         cmd.args(args);
 
-        Ok(DiscoverHandle { _handle: CommandHandle::spawn(cmd, self.sender.clone())? })
+        Ok(DiscoverHandle {
+            _handle: CommandHandle::spawn(cmd, self.sender.clone())?,
+            span: info_span!("discover_command").entered(),
+        })
     }
 }
 
 /// A handle to a spawned [Discover].
 #[derive(Debug)]
 pub(crate) struct DiscoverHandle {
     _handle: CommandHandle<DiscoverProjectMessage>,
+    #[allow(dead_code)] // not accessed, but used to log on drop.
+    span: EnteredSpan,
 }
 
 /// An enum containing either progress messages, an error,

crates/rust-analyzer/src/global_state.rs

@@ -111,6 +111,9 @@ pub(crate) struct GlobalState {
     pub(crate) vfs_config_version: u32,
     pub(crate) vfs_progress_config_version: u32,
     pub(crate) vfs_done: bool,
+    // used to track how long VFS loading takes. this can't be on `vfs::loader::Handle`,
+    // as that handle's lifetime is the same as `GlobalState` itself.
+    pub(crate) vfs_span: Option<tracing::span::EnteredSpan>,
     pub(crate) wants_to_switch: Option<Cause>,
 
     /// `workspaces` field stores the data we actually use, while the `OpQueue`
@@ -253,6 +256,7 @@ impl GlobalState {
             vfs: Arc::new(RwLock::new((vfs::Vfs::default(), IntMap::default()))),
             vfs_config_version: 0,
             vfs_progress_config_version: 0,
+            vfs_span: None,
             vfs_done: true,
             wants_to_switch: None,
 

crates/rust-analyzer/src/main_loop.rs

@@ -794,13 +794,20 @@ impl GlobalState {
                 }
             }
             vfs::loader::Message::Progress { n_total, n_done, dir, config_version } => {
-                let _p = tracing::info_span!("GlobalState::handle_vfs_mgs/progress").entered();
+                let _p = span!(Level::INFO, "GlobalState::handle_vfs_mgs/progress").entered();
                 always!(config_version <= self.vfs_config_version);
 
                 let (n_done, state) = match n_done {
-                    LoadingProgress::Started => (0, Progress::Begin),
+                    LoadingProgress::Started => {
+                        self.vfs_span =
+                            Some(span!(Level::INFO, "vfs_load", total = n_total).entered());
+                        (0, Progress::Begin)
+                    }
                     LoadingProgress::Progress(n_done) => (n_done.min(n_total), Progress::Report),
-                    LoadingProgress::Finished => (n_total, Progress::End),
+                    LoadingProgress::Finished => {
+                        self.vfs_span = None;
+                        (n_total, Progress::End)
+                    }
                 };
 
                 self.vfs_progress_config_version = config_version;
@@ -881,6 +888,7 @@ impl GlobalState {
             .expect("No title could be found; this is a bug");
         match message {
             DiscoverProjectMessage::Finished { project, buildfile } => {
+                self.discover_handle = None;
                 self.report_progress(&title, Progress::End, None, None, None);
                 self.discover_workspace_queue.op_completed(());
 
@@ -892,6 +900,7 @@ impl GlobalState {
                 self.report_progress(&title, Progress::Report, Some(message), None, None)
             }
             DiscoverProjectMessage::Error { error, source } => {
+                self.discover_handle = None;
                 let message = format!("Project discovery failed: {error}");
                 self.discover_workspace_queue.op_completed(());
                 self.show_and_log_error(message.clone(), source);

crates/rust-analyzer/src/tracing/config.rs

@@ -50,6 +50,7 @@ where
 
         let ra_fmt_layer = tracing_subscriber::fmt::layer()
             .with_target(false)
+            .with_ansi(false)
             .with_writer(writer)
             .with_filter(filter);