analysis-stats: Add body lowering step, track time of each step separtely

crates/rust-analyzer/src/cli/analysis_stats.rs

@@ -29,7 +29,6 @@ use profile::{Bytes, StopWatch};
 use project_model::{CargoConfig, ProjectManifest, ProjectWorkspace, RustLibSource};
 use rayon::prelude::*;
 use rustc_hash::FxHashSet;
-use stdx::format_to;
 use syntax::{AstNode, SyntaxNode};
 use vfs::{AbsPathBuf, Vfs, VfsPath};
 
@@ -176,8 +175,11 @@ impl flags::AnalysisStats {
             shuffle(&mut rng, &mut bodies);
         }
 
+        if !self.skip_lowering {
+            self.run_body_lowering(db, &vfs, &bodies, verbosity);
+        }
+
         if !self.skip_inference {
-            // FIXME: Consider running inference on all body kinds?
             self.run_inference(db, &vfs, &bodies, verbosity);
         }
 
@@ -238,8 +240,10 @@ impl flags::AnalysisStats {
                 continue;
             }
             all += 1;
-            let Err(e) = db.layout_of_adt(hir_def::AdtId::from(a).into(), Substitution::empty(Interner), a.krate(db).into()) else {
-                continue;
+            let Err(e)
+                = db.layout_of_adt(hir_def::AdtId::from(a).into(), Substitution::empty(Interner), a.krate(db).into())
+            else {
+                continue
             };
             if verbosity.is_spammy() {
                 let full_name = a
@@ -255,9 +259,11 @@ impl flags::AnalysisStats {
             }
             fail += 1;
         }
-        eprintln!("{:<20} {}", "Data layouts:", sw.elapsed());
+        let data_layout_time = sw.elapsed();
+        eprintln!("{:<20} {}", "Data layouts:", data_layout_time);
         eprintln!("Failed data layouts: {fail} ({}%)", percentage(fail, all));
         report_metric("failed data layouts", fail, "#");
+        report_metric("data layout time", data_layout_time.time.as_millis() as u64, "ms");
     }
 
     fn run_const_eval(&self, db: &RootDatabase, consts: &[hir::Const], verbosity: Verbosity) {
@@ -283,9 +289,11 @@ impl flags::AnalysisStats {
             }
             fail += 1;
         }
-        eprintln!("{:<20} {}", "Const evaluation:", sw.elapsed());
+        let const_eval_time = sw.elapsed();
+        eprintln!("{:<20} {}", "Const evaluation:", const_eval_time);
         eprintln!("Failed const evals: {fail} ({}%)", percentage(fail, all));
         report_metric("failed const evals", fail, "#");
+        report_metric("const eval time", const_eval_time.time.as_millis() as u64, "ms");
     }
 
     fn run_mir_lowering(&self, db: &RootDatabase, bodies: &[DefWithBody], verbosity: Verbosity) {
@@ -310,9 +318,11 @@ impl flags::AnalysisStats {
             }
             fail += 1;
         }
-        eprintln!("{:<20} {}", "MIR lowering:", sw.elapsed());
+        let mir_lowering_time = sw.elapsed();
+        eprintln!("{:<20} {}", "MIR lowering:", mir_lowering_time);
         eprintln!("Mir failed bodies: {fail} ({}%)", percentage(fail, all));
         report_metric("mir failed bodies", fail, "#");
+        report_metric("mir lowering time", mir_lowering_time.time.as_millis() as u64, "ms");
     }
 
     fn run_inference(
@@ -354,7 +364,7 @@ impl flags::AnalysisStats {
         for &body_id in bodies {
             let name = body_id.name(db).unwrap_or_else(Name::missing);
             let module = body_id.module(db);
-            let full_name = || {
+            let full_name = move || {
                 module
                     .krate()
                     .display_name(db)
@@ -366,7 +376,7 @@ impl flags::AnalysisStats {
                             .into_iter()
                             .filter_map(|it| it.name(db))
                             .rev()
-                            .chain(Some(name.clone()))
+                            .chain(Some(body_id.name(db).unwrap_or_else(Name::missing)))
                             .map(|it| it.display(db).to_string()),
                     )
                     .join("::")
@@ -376,26 +386,31 @@ impl flags::AnalysisStats {
                     continue;
                 }
             }
-            let mut msg = format!("processing: {}", full_name());
-            if verbosity.is_verbose() {
-                let source = match body_id {
-                    DefWithBody::Function(it) => it.source(db).map(|it| it.syntax().cloned()),
-                    DefWithBody::Static(it) => it.source(db).map(|it| it.syntax().cloned()),
-                    DefWithBody::Const(it) => it.source(db).map(|it| it.syntax().cloned()),
-                    DefWithBody::Variant(it) => it.source(db).map(|it| it.syntax().cloned()),
-                    DefWithBody::InTypeConst(_) => unimplemented!(),
-                };
-                if let Some(src) = source {
-                    let original_file = src.file_id.original_file(db);
-                    let path = vfs.file_path(original_file);
-                    let syntax_range = src.value.text_range();
-                    format_to!(msg, " ({} {:?})", path, syntax_range);
+            let msg = move || {
+                if verbosity.is_verbose() {
+                    let source = match body_id {
+                        DefWithBody::Function(it) => it.source(db).map(|it| it.syntax().cloned()),
+                        DefWithBody::Static(it) => it.source(db).map(|it| it.syntax().cloned()),
+                        DefWithBody::Const(it) => it.source(db).map(|it| it.syntax().cloned()),
+                        DefWithBody::Variant(it) => it.source(db).map(|it| it.syntax().cloned()),
+                        DefWithBody::InTypeConst(_) => unimplemented!(),
+                    };
+                    if let Some(src) = source {
+                        let original_file = src.file_id.original_file(db);
+                        let path = vfs.file_path(original_file);
+                        let syntax_range = src.value.text_range();
+                        format!("processing: {} ({} {:?})", full_name(), path, syntax_range)
+                    } else {
+                        format!("processing: {}", full_name())
+                    }
+                } else {
+                    format!("processing: {}", full_name())
                 }
-            }
+            };
             if verbosity.is_spammy() {
-                bar.println(msg.to_string());
+                bar.println(msg());
             }
-            bar.set_message(&msg);
+            bar.set_message(msg);
             let (body, sm) = db.body_with_source_map(body_id.into());
             let inference_result = db.infer(body_id.into());
 
@@ -596,6 +611,7 @@ impl flags::AnalysisStats {
         }
 
         bar.finish_and_clear();
+        let inference_time = inference_sw.elapsed();
         eprintln!(
             "  exprs: {}, ??ty: {} ({}%), ?ty: {} ({}%), !ty: {}",
             num_exprs,
@@ -614,12 +630,89 @@ impl flags::AnalysisStats {
             percentage(num_pats_partially_unknown, num_pats),
             num_pat_type_mismatches
         );
+        eprintln!("{:<20} {}", "Inference:", inference_time);
         report_metric("unknown type", num_exprs_unknown, "#");
         report_metric("type mismatches", num_expr_type_mismatches, "#");
         report_metric("pattern unknown type", num_pats_unknown, "#");
         report_metric("pattern type mismatches", num_pat_type_mismatches, "#");
+        report_metric("inference time", inference_time.time.as_millis() as u64, "ms");
+    }
 
-        eprintln!("{:<20} {}", "Inference:", inference_sw.elapsed());
+    fn run_body_lowering(
+        &self,
+        db: &RootDatabase,
+        vfs: &Vfs,
+        bodies: &[DefWithBody],
+        verbosity: Verbosity,
+    ) {
+        let mut bar = match verbosity {
+            Verbosity::Quiet | Verbosity::Spammy => ProgressReport::hidden(),
+            _ if self.output.is_some() => ProgressReport::hidden(),
+            _ => ProgressReport::new(bodies.len() as u64),
+        };
+
+        let mut sw = self.stop_watch();
+        bar.tick();
+        for &body_id in bodies {
+            let module = body_id.module(db);
+            let full_name = move || {
+                module
+                    .krate()
+                    .display_name(db)
+                    .map(|it| it.canonical_name().to_string())
+                    .into_iter()
+                    .chain(
+                        module
+                            .path_to_root(db)
+                            .into_iter()
+                            .filter_map(|it| it.name(db))
+                            .rev()
+                            .chain(Some(body_id.name(db).unwrap_or_else(Name::missing)))
+                            .map(|it| it.display(db).to_string()),
+                    )
+                    .join("::")
+            };
+            if let Some(only_name) = self.only.as_deref() {
+                if body_id.name(db).unwrap_or_else(Name::missing).display(db).to_string()
+                    != only_name
+                    && full_name() != only_name
+                {
+                    continue;
+                }
+            }
+            let msg = move || {
+                if verbosity.is_verbose() {
+                    let source = match body_id {
+                        DefWithBody::Function(it) => it.source(db).map(|it| it.syntax().cloned()),
+                        DefWithBody::Static(it) => it.source(db).map(|it| it.syntax().cloned()),
+                        DefWithBody::Const(it) => it.source(db).map(|it| it.syntax().cloned()),
+                        DefWithBody::Variant(it) => it.source(db).map(|it| it.syntax().cloned()),
+                        DefWithBody::InTypeConst(_) => unimplemented!(),
+                    };
+                    if let Some(src) = source {
+                        let original_file = src.file_id.original_file(db);
+                        let path = vfs.file_path(original_file);
+                        let syntax_range = src.value.text_range();
+                        format!("processing: {} ({} {:?})", full_name(), path, syntax_range)
+                    } else {
+                        format!("processing: {}", full_name())
+                    }
+                } else {
+                    format!("processing: {}", full_name())
+                }
+            };
+            if verbosity.is_spammy() {
+                bar.println(msg());
+            }
+            bar.set_message(msg);
+            db.body_with_source_map(body_id.into());
+            bar.inc(1);
+        }
+
+        bar.finish_and_clear();
+        let body_lowering_time = sw.elapsed();
+        eprintln!("{:<20} {}", "Body lowering:", body_lowering_time);
+        report_metric("body lowering time", body_lowering_time.time.as_millis() as u64, "ms");
     }
 
     fn stop_watch(&self) -> StopWatch {

crates/rust-analyzer/src/cli/flags.rs

@@ -78,6 +78,8 @@ xflags::xflags! {
             optional --disable-build-scripts
             /// Don't use expand proc macros.
             optional --disable-proc-macros
+            /// Skip body lowering.
+            optional --skip-lowering
             /// Skip type inference.
             optional --skip-inference
             /// Skip lowering to mir
@@ -180,6 +182,7 @@ pub struct AnalysisStats {
     pub parallel: bool,
     pub memory_usage: bool,
     pub source_stats: bool,
+    pub skip_lowering: bool,
     pub skip_inference: bool,
     pub skip_mir_stats: bool,
     pub skip_data_layout: bool,

crates/rust-analyzer/src/cli/progress_report.rs

@@ -4,41 +4,29 @@
 use std::io::{self, Write};
 
 /// A Simple ASCII Progress Bar
-pub(crate) struct ProgressReport {
+pub(crate) struct ProgressReport<'a> {
     curr: f32,
     text: String,
     hidden: bool,
 
     len: u64,
     pos: u64,
-    msg: String,
+    msg: Option<Box<dyn Fn() -> String + 'a>>,
 }
 
-impl ProgressReport {
-    pub(crate) fn new(len: u64) -> ProgressReport {
-        ProgressReport {
-            curr: 0.0,
-            text: String::new(),
-            hidden: false,
-            len,
-            pos: 0,
-            msg: String::new(),
-        }
+impl<'a> ProgressReport<'a> {
+    pub(crate) fn new(len: u64) -> ProgressReport<'a> {
+        ProgressReport { curr: 0.0, text: String::new(), hidden: false, len, pos: 0, msg: None }
     }
 
-    pub(crate) fn hidden() -> ProgressReport {
-        ProgressReport {
-            curr: 0.0,
-            text: String::new(),
-            hidden: true,
-            len: 0,
-            pos: 0,
-            msg: String::new(),
-        }
+    pub(crate) fn hidden() -> ProgressReport<'a> {
+        ProgressReport { curr: 0.0, text: String::new(), hidden: true, len: 0, pos: 0, msg: None }
     }
 
-    pub(crate) fn set_message(&mut self, msg: &str) {
-        self.msg = msg.to_string();
+    pub(crate) fn set_message(&mut self, msg: impl Fn() -> String + 'a) {
+        if !self.hidden {
+            self.msg = Some(Box::new(msg));
+        }
         self.tick();
     }
 
@@ -67,7 +55,12 @@ impl ProgressReport {
             return;
         }
         let percent = (self.curr * 100.0) as u32;
-        let text = format!("{}/{} {percent:3>}% {}", self.pos, self.len, self.msg);
+        let text = format!(
+            "{}/{} {percent:3>}% {}",
+            self.pos,
+            self.len,
+            self.msg.as_ref().map_or_else(|| String::new(), |it| it())
+        );
         self.update_text(&text);
     }