Auto merge of rust-lang#12009 - matklad:debug-reloads, r=matklad

bors · bors · commit dc6aa056fd5e · 2022-04-16T12:18:00.000Z
internal: more visibility into why things happen
diff --git a/crates/rust-analyzer/src/global_state.rs b/crates/rust-analyzer/src/global_state.rs
@@ -192,7 +192,8 @@ impl GlobalState {
                 if let Some(path) = vfs.file_path(file.file_id).as_path() {
                     let path = path.to_path_buf();
                     if reload::should_refresh_for_change(&path, file.change_kind) {
-                        self.fetch_workspaces_queue.request_op();
+                        self.fetch_workspaces_queue
+                            .request_op(format!("vfs file change: {}", path.display()));
                     }
                     fs_changes.push((path, file.change_kind));
                     if file.is_created_or_deleted() {
diff --git a/crates/rust-analyzer/src/main_loop.rs b/crates/rust-analyzer/src/main_loop.rs
@@ -149,9 +149,9 @@ impl GlobalState {
             );
         }
 
-        self.fetch_workspaces_queue.request_op();
-        if self.fetch_workspaces_queue.should_start_op() {
-            self.fetch_workspaces();
+        self.fetch_workspaces_queue.request_op("startup".to_string());
+        if let Some(cause) = self.fetch_workspaces_queue.should_start_op() {
+            self.fetch_workspaces(cause);
         }
 
         while let Some(event) = self.next_event(&inbox) {
@@ -240,7 +240,8 @@ impl GlobalState {
                                     let workspaces_updated = !Arc::ptr_eq(&old, &self.workspaces);
 
                                     if self.config.run_build_scripts() && workspaces_updated {
-                                        self.fetch_build_data_queue.request_op()
+                                        self.fetch_build_data_queue
+                                            .request_op(format!("workspace updated"));
                                     }
 
                                     (Progress::End, None)
@@ -312,7 +313,8 @@ impl GlobalState {
 
                             self.prime_caches_queue.op_completed(());
                             if cancelled {
-                                self.prime_caches_queue.request_op();
+                                self.prime_caches_queue
+                                    .request_op("restart after cancelation".to_string());
                             }
                         }
                     };
@@ -443,7 +445,7 @@ impl GlobalState {
                     flycheck.update();
                 }
                 if self.config.prefill_caches() {
-                    self.prime_caches_queue.request_op();
+                    self.prime_caches_queue.request_op("became quiescent".to_string());
                 }
             }
 
@@ -493,14 +495,15 @@ impl GlobalState {
         }
 
         if self.config.cargo_autoreload() {
-            if self.fetch_workspaces_queue.should_start_op() {
-                self.fetch_workspaces();
+            if let Some(cause) = self.fetch_workspaces_queue.should_start_op() {
+                self.fetch_workspaces(cause);
             }
         }
-        if self.fetch_build_data_queue.should_start_op() {
-            self.fetch_build_data();
+        if let Some(cause) = self.fetch_build_data_queue.should_start_op() {
+            self.fetch_build_data(cause);
         }
-        if self.prime_caches_queue.should_start_op() {
+        if let Some(cause) = self.prime_caches_queue.should_start_op() {
+            tracing::debug!(%cause, "will prime caches");
             let num_worker_threads = self.config.prime_caches_num_threads();
 
             self.task_pool.handle.spawn_with_sender({
@@ -569,7 +572,7 @@ impl GlobalState {
 
         RequestDispatcher { req: Some(req), global_state: self }
             .on_sync_mut::<lsp_ext::ReloadWorkspace>(|s, ()| {
-                s.fetch_workspaces_queue.request_op();
+                s.fetch_workspaces_queue.request_op("reload workspace request".to_string());
                 Ok(())
             })?
             .on_sync_mut::<lsp_types::request::Shutdown>(|s, ()| {
@@ -714,7 +717,7 @@ impl GlobalState {
                 }
                 if let Ok(abs_path) = from_proto::abs_path(&params.text_document.uri) {
                     if reload::should_refresh_for_change(&abs_path, ChangeKind::Modify) {
-                        this.fetch_workspaces_queue.request_op();
+                        this.fetch_workspaces_queue.request_op(format!("DidSaveTextDocument {}", abs_path.display()));
                     }
                 }
                 Ok(())
diff --git a/crates/rust-analyzer/src/op_queue.rs b/crates/rust-analyzer/src/op_queue.rs
@@ -1,29 +1,30 @@
 //! Bookkeeping to make sure only one long-running operation is being executed
 //! at a time.
 
+pub(crate) type Cause = String;
+
 pub(crate) struct OpQueue<Output> {
-    op_requested: bool,
+    op_requested: Option<Cause>,
     op_in_progress: bool,
     last_op_result: Output,
 }
 
 impl<Output: Default> Default for OpQueue<Output> {
     fn default() -> Self {
-        Self { op_requested: false, op_in_progress: false, last_op_result: Default::default() }
+        Self { op_requested: None, op_in_progress: false, last_op_result: Default::default() }
     }
 }
 
 impl<Output> OpQueue<Output> {
-    pub(crate) fn request_op(&mut self) {
-        self.op_requested = true;
+    pub(crate) fn request_op(&mut self, reason: Cause) {
+        self.op_requested = Some(reason);
     }
-    pub(crate) fn should_start_op(&mut self) -> bool {
+    pub(crate) fn should_start_op(&mut self) -> Option<Cause> {
         if self.op_in_progress {
-            return false;
+            return None;
         }
-        self.op_in_progress = self.op_requested;
-        self.op_requested = false;
-        self.op_in_progress
+        self.op_in_progress = self.op_requested.is_some();
+        self.op_requested.take()
     }
     pub(crate) fn op_completed(&mut self, result: Output) {
         assert!(self.op_in_progress);
@@ -38,6 +39,6 @@ impl<Output> OpQueue<Output> {
         self.op_in_progress
     }
     pub(crate) fn op_requested(&self) -> bool {
-        self.op_requested
+        self.op_requested.is_some()
     }
 }
diff --git a/crates/rust-analyzer/src/reload.rs b/crates/rust-analyzer/src/reload.rs
@@ -18,6 +18,7 @@ use crate::{
     global_state::GlobalState,
     lsp_ext,
     main_loop::Task,
+    op_queue::Cause,
 };
 
 #[derive(Debug)]
@@ -49,7 +50,7 @@ impl GlobalState {
             self.analysis_host.update_lru_capacity(self.config.lru_capacity());
         }
         if self.config.linked_projects() != old_config.linked_projects() {
-            self.fetch_workspaces_queue.request_op()
+            self.fetch_workspaces_queue.request_op("linked projects changed".to_string())
         } else if self.config.flycheck() != old_config.flycheck() {
             self.reload_flycheck();
         }
@@ -92,8 +93,8 @@ impl GlobalState {
         status
     }
 
-    pub(crate) fn fetch_workspaces(&mut self) {
-        tracing::info!("will fetch workspaces");
+    pub(crate) fn fetch_workspaces(&mut self, cause: Cause) {
+        tracing::info!(%cause, "will fetch workspaces");
 
         self.task_pool.handle.spawn_with_sender({
             let linked_projects = self.config.linked_projects();
@@ -144,7 +145,8 @@ impl GlobalState {
         });
     }
 
-    pub(crate) fn fetch_build_data(&mut self) {
+    pub(crate) fn fetch_build_data(&mut self, cause: Cause) {
+        tracing::debug!(%cause, "will fetch build data");
         let workspaces = Arc::clone(&self.workspaces);
         let config = self.config.cargo();
         self.task_pool.handle.spawn_with_sender(move |sender| {

Original file line number	Diff line number	Diff line change
`@@ -149,9 +149,9 @@ impl GlobalState {`
`149`	`149`	`);`
`150`	`150`	`}`
`151`	`151`
`152`		`- self.fetch_workspaces_queue.request_op();`
`153`		`- if self.fetch_workspaces_queue.should_start_op() {`
`154`		`- self.fetch_workspaces();`
	`152`	`+ self.fetch_workspaces_queue.request_op("startup".to_string());`
	`153`	`+ if let Some(cause) = self.fetch_workspaces_queue.should_start_op() {`
	`154`	`+ self.fetch_workspaces(cause);`
`155`	`155`	`}`
`156`	`156`
`157`	`157`	`while let Some(event) = self.next_event(&inbox) {`
`@@ -240,7 +240,8 @@ impl GlobalState {`
`240`	`240`	`let workspaces_updated = !Arc::ptr_eq(&old, &self.workspaces);`
`241`	`241`
`242`	`242`	`if self.config.run_build_scripts() && workspaces_updated {`
`243`		`- self.fetch_build_data_queue.request_op()`
	`243`	`+ self.fetch_build_data_queue`
	`244`	`+ .request_op(format!("workspace updated"));`
`244`	`245`	`}`
`245`	`246`
`246`	`247`	`(Progress::End, None)`
`@@ -312,7 +313,8 @@ impl GlobalState {`
`312`	`313`
`313`	`314`	`self.prime_caches_queue.op_completed(());`
`314`	`315`	`if cancelled {`
`315`		`- self.prime_caches_queue.request_op();`
	`316`	`+ self.prime_caches_queue`
	`317`	`+ .request_op("restart after cancelation".to_string());`
`316`	`318`	`}`
`317`	`319`	`}`
`318`	`320`	`};`
`@@ -443,7 +445,7 @@ impl GlobalState {`
`443`	`445`	`flycheck.update();`
`444`	`446`	`}`
`445`	`447`	`if self.config.prefill_caches() {`
`446`		`- self.prime_caches_queue.request_op();`
	`448`	`+ self.prime_caches_queue.request_op("became quiescent".to_string());`
`447`	`449`	`}`
`448`	`450`	`}`
`449`	`451`
`@@ -493,14 +495,15 @@ impl GlobalState {`
`493`	`495`	`}`
`494`	`496`
`495`	`497`	`if self.config.cargo_autoreload() {`
`496`		`- if self.fetch_workspaces_queue.should_start_op() {`
`497`		`- self.fetch_workspaces();`
	`498`	`+ if let Some(cause) = self.fetch_workspaces_queue.should_start_op() {`
	`499`	`+ self.fetch_workspaces(cause);`
`498`	`500`	`}`
`499`	`501`	`}`
`500`		`- if self.fetch_build_data_queue.should_start_op() {`
`501`		`- self.fetch_build_data();`
	`502`	`+ if let Some(cause) = self.fetch_build_data_queue.should_start_op() {`
	`503`	`+ self.fetch_build_data(cause);`
`502`	`504`	`}`
`503`		`- if self.prime_caches_queue.should_start_op() {`
	`505`	`+ if let Some(cause) = self.prime_caches_queue.should_start_op() {`
	`506`	`+ tracing::debug!(%cause, "will prime caches");`
`504`	`507`	`let num_worker_threads = self.config.prime_caches_num_threads();`
`505`	`508`
`506`	`509`	`self.task_pool.handle.spawn_with_sender({`
`@@ -569,7 +572,7 @@ impl GlobalState {`
`569`	`572`
`570`	`573`	`RequestDispatcher { req: Some(req), global_state: self }`
`571`	`574`	`.on_sync_mut::<lsp_ext::ReloadWorkspace>(\|s, ()\| {`
`572`		`- s.fetch_workspaces_queue.request_op();`
	`575`	`+ s.fetch_workspaces_queue.request_op("reload workspace request".to_string());`
`573`	`576`	`Ok(())`
`574`	`577`	`})?`
`575`	`578`	`.on_sync_mut::<lsp_types::request::Shutdown>(\|s, ()\| {`
`@@ -714,7 +717,7 @@ impl GlobalState {`
`714`	`717`	`}`
`715`	`718`	`if let Ok(abs_path) = from_proto::abs_path(&params.text_document.uri) {`
`716`	`719`	`if reload::should_refresh_for_change(&abs_path, ChangeKind::Modify) {`
`717`		`- this.fetch_workspaces_queue.request_op();`
	`720`	`+ this.fetch_workspaces_queue.request_op(format!("DidSaveTextDocument {}", abs_path.display()));`
`718`	`721`	`}`
`719`	`722`	`}`
`720`	`723`	`Ok(())`
Original file line number	Diff line number	Diff line change
`@@ -1,29 +1,30 @@`
`1`	`1`	`//! Bookkeeping to make sure only one long-running operation is being executed`
`2`	`2`	`//! at a time.`
`3`	`3`
	`4`	`+pub(crate) type Cause = String;`
	`5`	`+`
`4`	`6`	`pub(crate) struct OpQueue<Output> {`
`5`		`- op_requested: bool,`
	`7`	`+ op_requested: Option<Cause>,`
`6`	`8`	`op_in_progress: bool,`
`7`	`9`	`last_op_result: Output,`
`8`	`10`	`}`
`9`	`11`
`10`	`12`	`impl<Output: Default> Default for OpQueue<Output> {`
`11`	`13`	`fn default() -> Self {`
`12`		`- Self { op_requested: false, op_in_progress: false, last_op_result: Default::default() }`
	`14`	`+ Self { op_requested: None, op_in_progress: false, last_op_result: Default::default() }`
`13`	`15`	`}`
`14`	`16`	`}`
`15`	`17`
`16`	`18`	`impl<Output> OpQueue<Output> {`
`17`		`- pub(crate) fn request_op(&mut self) {`
`18`		`- self.op_requested = true;`
	`19`	`+ pub(crate) fn request_op(&mut self, reason: Cause) {`
	`20`	`+ self.op_requested = Some(reason);`
`19`	`21`	`}`
`20`		`- pub(crate) fn should_start_op(&mut self) -> bool {`
	`22`	`+ pub(crate) fn should_start_op(&mut self) -> Option<Cause> {`
`21`	`23`	`if self.op_in_progress {`
`22`		`- return false;`
	`24`	`+ return None;`
`23`	`25`	`}`
`24`		`- self.op_in_progress = self.op_requested;`
`25`		`- self.op_requested = false;`
`26`		`- self.op_in_progress`
	`26`	`+ self.op_in_progress = self.op_requested.is_some();`
	`27`	`+ self.op_requested.take()`
`27`	`28`	`}`
`28`	`29`	`pub(crate) fn op_completed(&mut self, result: Output) {`
`29`	`30`	`assert!(self.op_in_progress);`
`@@ -38,6 +39,6 @@ impl<Output> OpQueue<Output> {`
`38`	`39`	`self.op_in_progress`
`39`	`40`	`}`
`40`	`41`	`pub(crate) fn op_requested(&self) -> bool {`
`41`		`- self.op_requested`
	`42`	`+ self.op_requested.is_some()`
`42`	`43`	`}`
`43`	`44`	`}`