chore: gather build time benchmarks too

xtask/Cargo.toml

@@ -25,3 +25,7 @@ tera = "1.20"
 json_comments = "0.2"
 is-root = "0.1"
 indexmap = { version = "2", features = ["serde"] }
+regex = "1"
+
+[dev-dependencies]
+pretty_assertions = "1"

xtask/src/benches.rs

@@ -0,0 +1,228 @@
+use std::{fs, path::Path};
+
+use anyhow::anyhow;
+use regex::Regex;
+use serde::Deserialize;
+
+#[derive(Debug, Deserialize)]
+struct Unit {
+    name: String,
+    target: String,
+    duration: f64,
+    rmeta_time: Option<f64>,
+}
+
+/// Extract `const UNIT_DATA = [...]`
+fn extract_unit_data(html: &str) -> Option<String> {
+    let re = Regex::new(r"(?s)const UNIT_DATA = (\[.*?\]);").ok()?;
+    let caps = re.captures(html)?;
+    Some(caps.get(1)?.as_str().to_string())
+}
+
+pub fn timings_html_to_criterion(
+    html: &str,
+    include_crates: Vec<String>,
+) -> Result<String, anyhow::Error> {
+    let json = extract_unit_data(&html).ok_or(anyhow!("UNIT_DATA not found in timings HTML"))?;
+
+    let units: Vec<Unit> = serde_json::from_str(&json)?;
+
+    Ok(convert(units, include_crates))
+}
+
+fn convert(units: Vec<Unit>, include_crates: Vec<String>) -> String {
+    let mut out = String::new();
+    let mut total_rmeta = 0.0;
+    let mut total_codegen = 0.0;
+    for u in units {
+        let crate_name = normalize(&u.name, &u.target);
+        if crate_name.contains("(test)") || !include_crates.contains(&crate_name) {
+            continue;
+        }
+
+        let rmeta_time = if let Some(rmeta_time) = u.rmeta_time {
+            rmeta_time
+        } else {
+            continue;
+        };
+
+        // Phase split (best-effort)
+        let total_compile_time_s = u.duration;
+        let codegen_time = u.duration - rmeta_time;
+
+        let meta_name = format!("{}::blocking_comp", crate_name);
+        let codegen_name = format!("{}::codegen", crate_name);
+        let total_time_name = format!("{}::total", crate_name);
+        total_rmeta += rmeta_time;
+        total_codegen += codegen_time;
+
+        write_metric(&mut out, &meta_name, rmeta_time);
+        write_metric(&mut out, &codegen_name, codegen_time);
+        write_metric(&mut out, &total_time_name, total_compile_time_s);
+    }
+    write_metric(&mut out, &format!("total::blocking_comp"), total_rmeta);
+    write_metric(&mut out, &format!("total::codegen"), total_codegen);
+    write_metric(
+        &mut out,
+        &format!("total::total"),
+        total_rmeta + total_codegen,
+    );
+
+    out
+}
+
+fn write_metric(out: &mut String, name: &str, seconds: f64) {
+    use std::fmt::Write;
+
+    let _ = writeln!(
+        out,
+        "build_time/{name}   time:   [{:.3} s {:.3} s {:.3} s]",
+        seconds, seconds, seconds
+    );
+}
+
+fn normalize(name: &str, target: &str) -> String {
+    if target.trim().is_empty() {
+        name.to_string()
+    } else {
+        format!("{} [{}]", name, target.trim())
+    }
+}
+
+pub fn read_cargo_timings_report(
+    build_dir: &Path,
+    include_crates: Vec<String>,
+) -> Result<String, anyhow::Error> {
+    let html = fs::read_to_string(
+        &build_dir
+            .join("target")
+            .join("cargo-timings")
+            .join("cargo-timing.html"),
+    )?;
+    let criterion = process_cargo_timings_report(&html, include_crates)?;
+    Ok(criterion)
+}
+
+fn process_cargo_timings_report(
+    html: &str,
+    include_crates: Vec<String>,
+) -> Result<String, anyhow::Error> {
+    let criterion = timings_html_to_criterion(&html, include_crates)?;
+    Ok(criterion)
+}
+
+#[cfg(test)]
+mod test {
+
+    use crate::benches::process_cargo_timings_report;
+
+    pub const TEST_TIMINGS: &str = include_str!("../test_assets/cargo_timings_cut.html");
+
+    #[test]
+    fn regression_test() {
+        let res = process_cargo_timings_report(
+            TEST_TIMINGS,
+            vec![
+                "bevy_mod_scripting_world".to_owned(),
+                "bevy_mod_scripting_display".to_owned(),
+                "bevy_mod_scripting_bindings_domain".to_owned(),
+                "bevy_mod_scripting_asset".to_owned(),
+                "ladfile".to_owned(),
+                "bevy_mod_scripting_script".to_owned(),
+                "bevy_mod_scripting_bindings".to_owned(),
+                "lua_language_server_lad_backend".to_owned(),
+                "mdbook_lad_preprocessor".to_owned(),
+                "bevy_mod_scripting_core".to_owned(),
+                "bevy_math_bms_bindings".to_owned(),
+                "bevy_mod_scripting_rhai".to_owned(),
+                "bevy_reflect_bms_bindings".to_owned(),
+                "bevy_input_bms_bindings".to_owned(),
+                "bevy_color_bms_bindings".to_owned(),
+                "bevy_time_bms_bindings".to_owned(),
+                "bevy_transform_bms_bindings".to_owned(),
+                "bevy_ecs_bms_bindings".to_owned(),
+                "bevy_core_pipeline_bms_bindings".to_owned(),
+                "ladfile_builder".to_owned(),
+                "bevy_mod_scripting_functions".to_owned(),
+                "script_integration_test_harness".to_owned(),
+                "bevy_mod_scripting".to_owned(),
+            ],
+        );
+
+        let metrics = res.unwrap();
+        let expected = r#"build_time/bevy_mod_scripting_world::blocking_comp   time:   [1.150 s 1.150 s 1.150 s]
+build_time/bevy_mod_scripting_world::codegen   time:   [0.340 s 0.340 s 0.340 s]
+build_time/bevy_mod_scripting_world::total   time:   [1.490 s 1.490 s 1.490 s]
+build_time/bevy_mod_scripting_display::blocking_comp   time:   [1.390 s 1.390 s 1.390 s]
+build_time/bevy_mod_scripting_display::codegen   time:   [0.540 s 0.540 s 0.540 s]
+build_time/bevy_mod_scripting_display::total   time:   [1.930 s 1.930 s 1.930 s]
+build_time/bevy_mod_scripting_bindings_domain::blocking_comp   time:   [0.720 s 0.720 s 0.720 s]
+build_time/bevy_mod_scripting_bindings_domain::codegen   time:   [0.220 s 0.220 s 0.220 s]
+build_time/bevy_mod_scripting_bindings_domain::total   time:   [0.940 s 0.940 s 0.940 s]
+build_time/bevy_mod_scripting_asset::blocking_comp   time:   [1.870 s 1.870 s 1.870 s]
+build_time/bevy_mod_scripting_asset::codegen   time:   [0.850 s 0.850 s 0.850 s]
+build_time/bevy_mod_scripting_asset::total   time:   [2.720 s 2.720 s 2.720 s]
+build_time/ladfile::blocking_comp   time:   [3.570 s 3.570 s 3.570 s]
+build_time/ladfile::codegen   time:   [6.840 s 6.840 s 6.840 s]
+build_time/ladfile::total   time:   [10.410 s 10.410 s 10.410 s]
+build_time/bevy_mod_scripting_script::blocking_comp   time:   [1.410 s 1.410 s 1.410 s]
+build_time/bevy_mod_scripting_script::codegen   time:   [2.830 s 2.830 s 2.830 s]
+build_time/bevy_mod_scripting_script::total   time:   [4.240 s 4.240 s 4.240 s]
+build_time/bevy_mod_scripting_bindings::blocking_comp   time:   [24.070 s 24.070 s 24.070 s]
+build_time/bevy_mod_scripting_bindings::codegen   time:   [8.880 s 8.880 s 8.880 s]
+build_time/bevy_mod_scripting_bindings::total   time:   [32.950 s 32.950 s 32.950 s]
+build_time/lua_language_server_lad_backend::blocking_comp   time:   [3.500 s 3.500 s 3.500 s]
+build_time/lua_language_server_lad_backend::codegen   time:   [4.230 s 4.230 s 4.230 s]
+build_time/lua_language_server_lad_backend::total   time:   [7.730 s 7.730 s 7.730 s]
+build_time/mdbook_lad_preprocessor::blocking_comp   time:   [3.880 s 3.880 s 3.880 s]
+build_time/mdbook_lad_preprocessor::codegen   time:   [4.890 s 4.890 s 4.890 s]
+build_time/mdbook_lad_preprocessor::total   time:   [8.770 s 8.770 s 8.770 s]
+build_time/bevy_mod_scripting_core::blocking_comp   time:   [8.140 s 8.140 s 8.140 s]
+build_time/bevy_mod_scripting_core::codegen   time:   [32.510 s 32.510 s 32.510 s]
+build_time/bevy_mod_scripting_core::total   time:   [40.650 s 40.650 s 40.650 s]
+build_time/bevy_math_bms_bindings::blocking_comp   time:   [15.110 s 15.110 s 15.110 s]
+build_time/bevy_math_bms_bindings::codegen   time:   [111.500 s 111.500 s 111.500 s]
+build_time/bevy_math_bms_bindings::total   time:   [126.610 s 126.610 s 126.610 s]
+build_time/bevy_mod_scripting_rhai::blocking_comp   time:   [9.320 s 9.320 s 9.320 s]
+build_time/bevy_mod_scripting_rhai::codegen   time:   [65.510 s 65.510 s 65.510 s]
+build_time/bevy_mod_scripting_rhai::total   time:   [74.830 s 74.830 s 74.830 s]
+build_time/bevy_reflect_bms_bindings::blocking_comp   time:   [81.840 s 81.840 s 81.840 s]
+build_time/bevy_reflect_bms_bindings::codegen   time:   [442.670 s 442.670 s 442.670 s]
+build_time/bevy_reflect_bms_bindings::total   time:   [524.510 s 524.510 s 524.510 s]
+build_time/bevy_input_bms_bindings::blocking_comp   time:   [5.830 s 5.830 s 5.830 s]
+build_time/bevy_input_bms_bindings::codegen   time:   [70.850 s 70.850 s 70.850 s]
+build_time/bevy_input_bms_bindings::total   time:   [76.680 s 76.680 s 76.680 s]
+build_time/bevy_color_bms_bindings::blocking_comp   time:   [4.420 s 4.420 s 4.420 s]
+build_time/bevy_color_bms_bindings::codegen   time:   [43.690 s 43.690 s 43.690 s]
+build_time/bevy_color_bms_bindings::total   time:   [48.110 s 48.110 s 48.110 s]
+build_time/bevy_time_bms_bindings::blocking_comp   time:   [2.290 s 2.290 s 2.290 s]
+build_time/bevy_time_bms_bindings::codegen   time:   [27.680 s 27.680 s 27.680 s]
+build_time/bevy_time_bms_bindings::total   time:   [29.970 s 29.970 s 29.970 s]
+build_time/bevy_transform_bms_bindings::blocking_comp   time:   [3.430 s 3.430 s 3.430 s]
+build_time/bevy_transform_bms_bindings::codegen   time:   [33.310 s 33.310 s 33.310 s]
+build_time/bevy_transform_bms_bindings::total   time:   [36.740 s 36.740 s 36.740 s]
+build_time/bevy_ecs_bms_bindings::blocking_comp   time:   [3.480 s 3.480 s 3.480 s]
+build_time/bevy_ecs_bms_bindings::codegen   time:   [35.010 s 35.010 s 35.010 s]
+build_time/bevy_ecs_bms_bindings::total   time:   [38.490 s 38.490 s 38.490 s]
+build_time/bevy_core_pipeline_bms_bindings::blocking_comp   time:   [4.270 s 4.270 s 4.270 s]
+build_time/bevy_core_pipeline_bms_bindings::codegen   time:   [19.850 s 19.850 s 19.850 s]
+build_time/bevy_core_pipeline_bms_bindings::total   time:   [24.120 s 24.120 s 24.120 s]
+build_time/ladfile_builder::blocking_comp   time:   [2.940 s 2.940 s 2.940 s]
+build_time/ladfile_builder::codegen   time:   [13.500 s 13.500 s 13.500 s]
+build_time/ladfile_builder::total   time:   [16.440 s 16.440 s 16.440 s]
+build_time/bevy_mod_scripting_functions::blocking_comp   time:   [12.570 s 12.570 s 12.570 s]
+build_time/bevy_mod_scripting_functions::codegen   time:   [55.070 s 55.070 s 55.070 s]
+build_time/bevy_mod_scripting_functions::total   time:   [67.640 s 67.640 s 67.640 s]
+build_time/script_integration_test_harness::blocking_comp   time:   [29.130 s 29.130 s 29.130 s]
+build_time/script_integration_test_harness::codegen   time:   [21.660 s 21.660 s 21.660 s]
+build_time/script_integration_test_harness::total   time:   [50.790 s 50.790 s 50.790 s]
+build_time/bevy_mod_scripting::blocking_comp   time:   [5.700 s 5.700 s 5.700 s]
+build_time/bevy_mod_scripting::codegen   time:   [0.650 s 0.650 s 0.650 s]
+build_time/bevy_mod_scripting::total   time:   [6.350 s 6.350 s 6.350 s]
+build_time/total::blocking_comp   time:   [230.030 s 230.030 s 230.030 s]
+build_time/total::codegen   time:   [1003.080 s 1003.080 s 1003.080 s]
+build_time/total::total   time:   [1233.110 s 1233.110 s 1233.110 s]
+"#;
+        pretty_assertions::assert_str_eq!(metrics, expected);
+    }
+}

xtask/src/lib.rs

@@ -1,11 +1,13 @@
 pub(crate) mod args;
+pub(crate) mod benches;
 pub(crate) mod binding_crate;
 pub(crate) mod codegen;
 pub(crate) mod codegen_meta;
 pub(crate) mod command;
 pub(crate) mod features;
 
 pub use args::*;
+pub use benches::*;
 pub use binding_crate::*;
 pub use codegen::*;
 pub use codegen_meta::*;

xtask/src/main.rs

@@ -1,7 +1,7 @@
 use std::{
     collections::HashMap,
     ffi::OsString,
-    io::Write,
+    io::{Write, stdout},
     path::{Path, PathBuf},
     process::{Command, Output},
     str::FromStr,
@@ -933,15 +933,15 @@ impl Xtasks {
             unsafe { std::env::set_var("RUST_LOG", "bevy_mod_scripting=error") };
         }
 
-        let args = if let Some(name) = name {
-            vec!["--".to_owned(), name]
-        } else {
-            vec![]
+        let mut args = vec!["--timings".to_owned()];
+
+        if let Some(name) = name {
+            args.extend(["--".to_owned(), name]);
         };
 
-        let output = run_workspace_command(
+        let mut output = run_workspace_command(
             // run with just lua54
-            &app_settings.with_features(features),
+            &app_settings.clone().with_features(features),
             "bench",
             "Failed to run benchmarks",
             args,
@@ -950,6 +950,24 @@ impl Xtasks {
         )
         .with_context(|| "when executing criterion benchmarks")?;
 
+        let workspace_dir = workspace_dir(&app_settings)?;
+        let metadata = main_workspace_cargo_metadata()?;
+        let crates = metadata
+            .workspace_packages()
+            .iter()
+            .map(|p| p.name.to_string())
+            .collect::<Vec<String>>();
+
+        info!("Gathering build time for crates: {}", crates.join(","));
+
+        let additional_benchmark_lines = xtask::read_cargo_timings_report(&workspace_dir, crates)?;
+
+        if !capture_streams_in_output {
+            stdout().write(additional_benchmark_lines.as_bytes())?;
+        } else {
+            output.stdout.write(additional_benchmark_lines.as_bytes())?;
+        }
+
         Ok(output)
     }