Skip to content

Commit 8fab266

Browse files
makspllmakspll
authored
chore: gather build time benchmarks too (#530)
1 parent a8bf277 commit 8fab266

File tree

5 files changed

+1190
-7
lines changed

5 files changed

+1190
-7
lines changed

‎xtask/Cargo.toml‎

Lines changed: 4 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -25,3 +25,7 @@ tera = "1.20"
2525
json_comments = "0.2"
2626
is-root = "0.1"
2727
indexmap = { version = "2", features = ["serde"] }
28+
regex = "1"
29+
30+
[dev-dependencies]
31+
pretty_assertions = "1"

‎xtask/src/benches.rs‎

Lines changed: 228 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,228 @@
1+
use std::{fs, path::Path};
2+
3+
use anyhow::anyhow;
4+
use regex::Regex;
5+
use serde::Deserialize;
6+
7+
#[derive(Debug, Deserialize)]
8+
struct Unit {
9+
name: String,
10+
target: String,
11+
duration: f64,
12+
rmeta_time: Option<f64>,
13+
}
14+
15+
/// Extract `const UNIT_DATA = [...]`
16+
fn extract_unit_data(html: &str) -> Option<String> {
17+
let re = Regex::new(r"(?s)const UNIT_DATA = (\[.*?\]);").ok()?;
18+
let caps = re.captures(html)?;
19+
Some(caps.get(1)?.as_str().to_string())
20+
}
21+
22+
pub fn timings_html_to_criterion(
23+
html: &str,
24+
include_crates: Vec<String>,
25+
) -> Result<String, anyhow::Error> {
26+
let json = extract_unit_data(&html).ok_or(anyhow!("UNIT_DATA not found in timings HTML"))?;
27+
28+
let units: Vec<Unit> = serde_json::from_str(&json)?;
29+
30+
Ok(convert(units, include_crates))
31+
}
32+
33+
fn convert(units: Vec<Unit>, include_crates: Vec<String>) -> String {
34+
let mut out = String::new();
35+
let mut total_rmeta = 0.0;
36+
let mut total_codegen = 0.0;
37+
for u in units {
38+
let crate_name = normalize(&u.name, &u.target);
39+
if crate_name.contains("(test)") || !include_crates.contains(&crate_name) {
40+
continue;
41+
}
42+
43+
let rmeta_time = if let Some(rmeta_time) = u.rmeta_time {
44+
rmeta_time
45+
} else {
46+
continue;
47+
};
48+
49+
// Phase split (best-effort)
50+
let total_compile_time_s = u.duration;
51+
let codegen_time = u.duration - rmeta_time;
52+
53+
let meta_name = format!("{}::blocking_comp", crate_name);
54+
let codegen_name = format!("{}::codegen", crate_name);
55+
let total_time_name = format!("{}::total", crate_name);
56+
total_rmeta += rmeta_time;
57+
total_codegen += codegen_time;
58+
59+
write_metric(&mut out, &meta_name, rmeta_time);
60+
write_metric(&mut out, &codegen_name, codegen_time);
61+
write_metric(&mut out, &total_time_name, total_compile_time_s);
62+
}
63+
write_metric(&mut out, &format!("total::blocking_comp"), total_rmeta);
64+
write_metric(&mut out, &format!("total::codegen"), total_codegen);
65+
write_metric(
66+
&mut out,
67+
&format!("total::total"),
68+
total_rmeta + total_codegen,
69+
);
70+
71+
out
72+
}
73+
74+
fn write_metric(out: &mut String, name: &str, seconds: f64) {
75+
use std::fmt::Write;
76+
77+
let _ = writeln!(
78+
out,
79+
"build_time/{name} time: [{:.3} s {:.3} s {:.3} s]",
80+
seconds, seconds, seconds
81+
);
82+
}
83+
84+
fn normalize(name: &str, target: &str) -> String {
85+
if target.trim().is_empty() {
86+
name.to_string()
87+
} else {
88+
format!("{} [{}]", name, target.trim())
89+
}
90+
}
91+
92+
pub fn read_cargo_timings_report(
93+
build_dir: &Path,
94+
include_crates: Vec<String>,
95+
) -> Result<String, anyhow::Error> {
96+
let html = fs::read_to_string(
97+
&build_dir
98+
.join("target")
99+
.join("cargo-timings")
100+
.join("cargo-timing.html"),
101+
)?;
102+
let criterion = process_cargo_timings_report(&html, include_crates)?;
103+
Ok(criterion)
104+
}
105+
106+
fn process_cargo_timings_report(
107+
html: &str,
108+
include_crates: Vec<String>,
109+
) -> Result<String, anyhow::Error> {
110+
let criterion = timings_html_to_criterion(&html, include_crates)?;
111+
Ok(criterion)
112+
}
113+
114+
#[cfg(test)]
115+
mod test {
116+
117+
use crate::benches::process_cargo_timings_report;
118+
119+
pub const TEST_TIMINGS: &str = include_str!("../test_assets/cargo_timings_cut.html");
120+
121+
#[test]
122+
fn regression_test() {
123+
let res = process_cargo_timings_report(
124+
TEST_TIMINGS,
125+
vec![
126+
"bevy_mod_scripting_world".to_owned(),
127+
"bevy_mod_scripting_display".to_owned(),
128+
"bevy_mod_scripting_bindings_domain".to_owned(),
129+
"bevy_mod_scripting_asset".to_owned(),
130+
"ladfile".to_owned(),
131+
"bevy_mod_scripting_script".to_owned(),
132+
"bevy_mod_scripting_bindings".to_owned(),
133+
"lua_language_server_lad_backend".to_owned(),
134+
"mdbook_lad_preprocessor".to_owned(),
135+
"bevy_mod_scripting_core".to_owned(),
136+
"bevy_math_bms_bindings".to_owned(),
137+
"bevy_mod_scripting_rhai".to_owned(),
138+
"bevy_reflect_bms_bindings".to_owned(),
139+
"bevy_input_bms_bindings".to_owned(),
140+
"bevy_color_bms_bindings".to_owned(),
141+
"bevy_time_bms_bindings".to_owned(),
142+
"bevy_transform_bms_bindings".to_owned(),
143+
"bevy_ecs_bms_bindings".to_owned(),
144+
"bevy_core_pipeline_bms_bindings".to_owned(),
145+
"ladfile_builder".to_owned(),
146+
"bevy_mod_scripting_functions".to_owned(),
147+
"script_integration_test_harness".to_owned(),
148+
"bevy_mod_scripting".to_owned(),
149+
],
150+
);
151+
152+
let metrics = res.unwrap();
153+
let expected = r#"build_time/bevy_mod_scripting_world::blocking_comp time: [1.150 s 1.150 s 1.150 s]
154+
build_time/bevy_mod_scripting_world::codegen time: [0.340 s 0.340 s 0.340 s]
155+
build_time/bevy_mod_scripting_world::total time: [1.490 s 1.490 s 1.490 s]
156+
build_time/bevy_mod_scripting_display::blocking_comp time: [1.390 s 1.390 s 1.390 s]
157+
build_time/bevy_mod_scripting_display::codegen time: [0.540 s 0.540 s 0.540 s]
158+
build_time/bevy_mod_scripting_display::total time: [1.930 s 1.930 s 1.930 s]
159+
build_time/bevy_mod_scripting_bindings_domain::blocking_comp time: [0.720 s 0.720 s 0.720 s]
160+
build_time/bevy_mod_scripting_bindings_domain::codegen time: [0.220 s 0.220 s 0.220 s]
161+
build_time/bevy_mod_scripting_bindings_domain::total time: [0.940 s 0.940 s 0.940 s]
162+
build_time/bevy_mod_scripting_asset::blocking_comp time: [1.870 s 1.870 s 1.870 s]
163+
build_time/bevy_mod_scripting_asset::codegen time: [0.850 s 0.850 s 0.850 s]
164+
build_time/bevy_mod_scripting_asset::total time: [2.720 s 2.720 s 2.720 s]
165+
build_time/ladfile::blocking_comp time: [3.570 s 3.570 s 3.570 s]
166+
build_time/ladfile::codegen time: [6.840 s 6.840 s 6.840 s]
167+
build_time/ladfile::total time: [10.410 s 10.410 s 10.410 s]
168+
build_time/bevy_mod_scripting_script::blocking_comp time: [1.410 s 1.410 s 1.410 s]
169+
build_time/bevy_mod_scripting_script::codegen time: [2.830 s 2.830 s 2.830 s]
170+
build_time/bevy_mod_scripting_script::total time: [4.240 s 4.240 s 4.240 s]
171+
build_time/bevy_mod_scripting_bindings::blocking_comp time: [24.070 s 24.070 s 24.070 s]
172+
build_time/bevy_mod_scripting_bindings::codegen time: [8.880 s 8.880 s 8.880 s]
173+
build_time/bevy_mod_scripting_bindings::total time: [32.950 s 32.950 s 32.950 s]
174+
build_time/lua_language_server_lad_backend::blocking_comp time: [3.500 s 3.500 s 3.500 s]
175+
build_time/lua_language_server_lad_backend::codegen time: [4.230 s 4.230 s 4.230 s]
176+
build_time/lua_language_server_lad_backend::total time: [7.730 s 7.730 s 7.730 s]
177+
build_time/mdbook_lad_preprocessor::blocking_comp time: [3.880 s 3.880 s 3.880 s]
178+
build_time/mdbook_lad_preprocessor::codegen time: [4.890 s 4.890 s 4.890 s]
179+
build_time/mdbook_lad_preprocessor::total time: [8.770 s 8.770 s 8.770 s]
180+
build_time/bevy_mod_scripting_core::blocking_comp time: [8.140 s 8.140 s 8.140 s]
181+
build_time/bevy_mod_scripting_core::codegen time: [32.510 s 32.510 s 32.510 s]
182+
build_time/bevy_mod_scripting_core::total time: [40.650 s 40.650 s 40.650 s]
183+
build_time/bevy_math_bms_bindings::blocking_comp time: [15.110 s 15.110 s 15.110 s]
184+
build_time/bevy_math_bms_bindings::codegen time: [111.500 s 111.500 s 111.500 s]
185+
build_time/bevy_math_bms_bindings::total time: [126.610 s 126.610 s 126.610 s]
186+
build_time/bevy_mod_scripting_rhai::blocking_comp time: [9.320 s 9.320 s 9.320 s]
187+
build_time/bevy_mod_scripting_rhai::codegen time: [65.510 s 65.510 s 65.510 s]
188+
build_time/bevy_mod_scripting_rhai::total time: [74.830 s 74.830 s 74.830 s]
189+
build_time/bevy_reflect_bms_bindings::blocking_comp time: [81.840 s 81.840 s 81.840 s]
190+
build_time/bevy_reflect_bms_bindings::codegen time: [442.670 s 442.670 s 442.670 s]
191+
build_time/bevy_reflect_bms_bindings::total time: [524.510 s 524.510 s 524.510 s]
192+
build_time/bevy_input_bms_bindings::blocking_comp time: [5.830 s 5.830 s 5.830 s]
193+
build_time/bevy_input_bms_bindings::codegen time: [70.850 s 70.850 s 70.850 s]
194+
build_time/bevy_input_bms_bindings::total time: [76.680 s 76.680 s 76.680 s]
195+
build_time/bevy_color_bms_bindings::blocking_comp time: [4.420 s 4.420 s 4.420 s]
196+
build_time/bevy_color_bms_bindings::codegen time: [43.690 s 43.690 s 43.690 s]
197+
build_time/bevy_color_bms_bindings::total time: [48.110 s 48.110 s 48.110 s]
198+
build_time/bevy_time_bms_bindings::blocking_comp time: [2.290 s 2.290 s 2.290 s]
199+
build_time/bevy_time_bms_bindings::codegen time: [27.680 s 27.680 s 27.680 s]
200+
build_time/bevy_time_bms_bindings::total time: [29.970 s 29.970 s 29.970 s]
201+
build_time/bevy_transform_bms_bindings::blocking_comp time: [3.430 s 3.430 s 3.430 s]
202+
build_time/bevy_transform_bms_bindings::codegen time: [33.310 s 33.310 s 33.310 s]
203+
build_time/bevy_transform_bms_bindings::total time: [36.740 s 36.740 s 36.740 s]
204+
build_time/bevy_ecs_bms_bindings::blocking_comp time: [3.480 s 3.480 s 3.480 s]
205+
build_time/bevy_ecs_bms_bindings::codegen time: [35.010 s 35.010 s 35.010 s]
206+
build_time/bevy_ecs_bms_bindings::total time: [38.490 s 38.490 s 38.490 s]
207+
build_time/bevy_core_pipeline_bms_bindings::blocking_comp time: [4.270 s 4.270 s 4.270 s]
208+
build_time/bevy_core_pipeline_bms_bindings::codegen time: [19.850 s 19.850 s 19.850 s]
209+
build_time/bevy_core_pipeline_bms_bindings::total time: [24.120 s 24.120 s 24.120 s]
210+
build_time/ladfile_builder::blocking_comp time: [2.940 s 2.940 s 2.940 s]
211+
build_time/ladfile_builder::codegen time: [13.500 s 13.500 s 13.500 s]
212+
build_time/ladfile_builder::total time: [16.440 s 16.440 s 16.440 s]
213+
build_time/bevy_mod_scripting_functions::blocking_comp time: [12.570 s 12.570 s 12.570 s]
214+
build_time/bevy_mod_scripting_functions::codegen time: [55.070 s 55.070 s 55.070 s]
215+
build_time/bevy_mod_scripting_functions::total time: [67.640 s 67.640 s 67.640 s]
216+
build_time/script_integration_test_harness::blocking_comp time: [29.130 s 29.130 s 29.130 s]
217+
build_time/script_integration_test_harness::codegen time: [21.660 s 21.660 s 21.660 s]
218+
build_time/script_integration_test_harness::total time: [50.790 s 50.790 s 50.790 s]
219+
build_time/bevy_mod_scripting::blocking_comp time: [5.700 s 5.700 s 5.700 s]
220+
build_time/bevy_mod_scripting::codegen time: [0.650 s 0.650 s 0.650 s]
221+
build_time/bevy_mod_scripting::total time: [6.350 s 6.350 s 6.350 s]
222+
build_time/total::blocking_comp time: [230.030 s 230.030 s 230.030 s]
223+
build_time/total::codegen time: [1003.080 s 1003.080 s 1003.080 s]
224+
build_time/total::total time: [1233.110 s 1233.110 s 1233.110 s]
225+
"#;
226+
pretty_assertions::assert_str_eq!(metrics, expected);
227+
}
228+
}

‎xtask/src/lib.rs‎

Lines changed: 2 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -1,11 +1,13 @@
11
pub(crate) mod args;
2+
pub(crate) mod benches;
23
pub(crate) mod binding_crate;
34
pub(crate) mod codegen;
45
pub(crate) mod codegen_meta;
56
pub(crate) mod command;
67
pub(crate) mod features;
78

89
pub use args::*;
10+
pub use benches::*;
911
pub use binding_crate::*;
1012
pub use codegen::*;
1113
pub use codegen_meta::*;

‎xtask/src/main.rs‎

Lines changed: 25 additions & 7 deletions
Original file line numberDiff line numberDiff line change
@@ -1,7 +1,7 @@
11
use std::{
22
collections::HashMap,
33
ffi::OsString,
4-
io::Write,
4+
io::{Write, stdout},
55
path::{Path, PathBuf},
66
process::{Command, Output},
77
str::FromStr,
@@ -933,15 +933,15 @@ impl Xtasks {
933933
unsafe { std::env::set_var("RUST_LOG", "bevy_mod_scripting=error") };
934934
}
935935

936-
let args = if let Some(name) = name {
937-
vec!["--".to_owned(), name]
938-
} else {
939-
vec![]
936+
let mut args = vec!["--timings".to_owned()];
937+
938+
if let Some(name) = name {
939+
args.extend(["--".to_owned(), name]);
940940
};
941941

942-
let output = run_workspace_command(
942+
let mut output = run_workspace_command(
943943
// run with just lua54
944-
&app_settings.with_features(features),
944+
&app_settings.clone().with_features(features),
945945
"bench",
946946
"Failed to run benchmarks",
947947
args,
@@ -950,6 +950,24 @@ impl Xtasks {
950950
)
951951
.with_context(|| "when executing criterion benchmarks")?;
952952

953+
let workspace_dir = workspace_dir(&app_settings)?;
954+
let metadata = main_workspace_cargo_metadata()?;
955+
let crates = metadata
956+
.workspace_packages()
957+
.iter()
958+
.map(|p| p.name.to_string())
959+
.collect::<Vec<String>>();
960+
961+
info!("Gathering build time for crates: {}", crates.join(","));
962+
963+
let additional_benchmark_lines = xtask::read_cargo_timings_report(&workspace_dir, crates)?;
964+
965+
if !capture_streams_in_output {
966+
stdout().write(additional_benchmark_lines.as_bytes())?;
967+
} else {
968+
output.stdout.write(additional_benchmark_lines.as_bytes())?;
969+
}
970+
953971
Ok(output)
954972
}
955973

0 commit comments

Comments
 (0)