internal: add tracing to project discovery and VFS loading

Author: davidbarsky

src/tools/rust-analyzer/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};
 
 usecrate::command::{CommandHandle,ParseFromLine};
 
@@ -60,14 +61,19 @@ impl DiscoverCommand {
 letmut 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)structDiscoverHandle{
 _handle:CommandHandle<DiscoverProjectMessage>,
+#[allow(dead_code)]// not accessed, but used to log on drop.
+span:EnteredSpan,
 }
 
 /// An enum containing either progress messages, an error,

src/tools/rust-analyzer/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,
 

src/tools/rust-analyzer/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);

src/tools/rust-analyzer/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);