1#![warn(clippy::all, clippy::pedantic, clippy::undocumented_unsafe_blocks)]
2#![cfg_attr(release, deny(warnings))]
3
4//! Perf profiler for Zed tests. Outputs timings of tests marked with the `#[perf]`
5//! attribute to stdout in Markdown. See the documentation of `util_macros::perf`
6//! for usage details on the actual attribute.
7//!
8//! # Setup
9//! Make sure `hyperfine` is installed and in the shell path, then run
10//! `cargo build --bin perf --workspace --release` to build the profiler.
11//!
12//! # Usage
13//! Calling this tool rebuilds everything with some cfg flags set for the perf
14//! proc macro *and* enables optimisations (`release-fast` profile), so expect it
15//! to take a little while.
16//!
17//! To test an individual crate, run:
18//! ```sh
19//! cargo perf-test -p $CRATE
20//! ```
21//!
22//! To test everything (which will be **VERY SLOW**), run:
23//! ```sh
24//! cargo perf-test --workspace
25//! ```
26//!
27//! # Notes
28//! This should probably not be called manually unless you're working on the profiler
29//! itself; use the `cargo perf-test` alias (after building this crate) instead.
30
31use std::{
32 process::{Command, Stdio},
33 time::{Duration, Instant},
34};
35
36/// How many iterations to attempt the first time a test is run.
37const DEFAULT_ITER_COUNT: usize = 12;
38/// Multiplier for the iteration count when a test doesn't pass the noise cutoff.
39const ITER_COUNT_MUL: usize = 4;
40/// How long a test must have run to be assumed to be reliable-ish.
41const NOISE_CUTOFF: Duration = Duration::from_millis(250);
42
43// If any of the below constants are changed, make sure to also update the perf
44// proc macro to match!
45
46/// The suffix on tests marked with `#[perf]`.
47const SUF_NORMAL: &str = "__ZED_PERF";
48/// The suffix on tests marked with `#[perf(iterations = n)]`.
49const SUF_FIXED: &str = "__ZED_PERF_FIXEDITER";
50/// The env var in which we pass the iteration count to our tests.
51const ITER_ENV_VAR: &str = "ZED_PERF_ITER";
52
53#[allow(clippy::too_many_lines)]
54fn main() {
55 // We get passed the test we need to run as the 1st argument after our own name.
56 let test_bin = std::env::args().nth(1).unwrap();
57 let mut cmd = Command::new(&test_bin);
58 // --format=json is nightly-only :(
59 cmd.args(["--list", "--format=terse"]);
60 let out = cmd
61 .output()
62 .expect("FATAL: Could not run test binary {test_bin}");
63 assert!(
64 out.status.success(),
65 "FATAL: Cannot do perf check - test binary {test_bin} returned an error"
66 );
67 // Parse the test harness output to look for tests we care about.
68 let stdout = String::from_utf8_lossy(&out.stdout);
69 let mut test_list: Vec<_> = stdout
70 .lines()
71 .filter_map(|line| {
72 // This should split only in two; e.g.,
73 // "app::test::test_arena: test" => "app::test::test_arena:", "test"
74 let line: Vec<_> = line.split_whitespace().collect();
75 match line[..] {
76 // Final byte of t_name is ":", which we need to ignore.
77 [t_name, kind] => (kind == "test").then(|| &t_name[..t_name.len() - 1]),
78 _ => None,
79 }
80 })
81 // Exclude tests that aren't marked for perf triage based on suffix.
82 .filter(|t_name| t_name.ends_with(SUF_NORMAL) || t_name.ends_with(SUF_FIXED))
83 .collect();
84
85 // Pulling itertools just for .dedup() would be quite a big dependency that's
86 // not used elsewhere, so do this on the vec instead.
87 test_list.sort_unstable();
88 test_list.dedup();
89
90 if !test_list.is_empty() {
91 // Print the markdown header which matches hyperfine's result.
92 // TODO: Support exporting JSON also.
93 println!(
94 "| Command | Mean [ms] | Min [ms] | Max [ms] | Iterations | Iter/sec |\n|:---|---:|---:|---:|---:|---:|"
95 );
96 }
97
98 // Spawn and profile an instance of each perf-sensitive test, via hyperfine.
99 for t_name in test_list {
100 // Pretty-print the stripped name for the test.
101 let t_name_normal = t_name.replace(SUF_FIXED, "").replace(SUF_NORMAL, "");
102 // Time test execution to see how many iterations we need to do in order
103 // to account for random noise. This is skipped for tests with fixed
104 // iteration counts.
105 let final_iter_count = if t_name.ends_with(SUF_FIXED) {
106 None
107 } else {
108 let mut iter_count = DEFAULT_ITER_COUNT;
109 loop {
110 let mut cmd = Command::new(&test_bin);
111 cmd.args([t_name, "--exact"]);
112 cmd.env(ITER_ENV_VAR, format!("{iter_count}"));
113 // Don't let the child muck up our stdin/out/err.
114 cmd.stdin(Stdio::null());
115 cmd.stdout(Stdio::null());
116 cmd.stderr(Stdio::null());
117 let pre = Instant::now();
118 // Discard the output beyond ensuring success.
119 let out = cmd.spawn().unwrap().wait();
120 let post = Instant::now();
121 if !out.unwrap().success() {
122 println!(
123 "| {t_name_normal} (ERRORED IN TRIAGE) | N/A | N/A | N/A | {iter_count} | N/A |"
124 );
125 return;
126 }
127 if post - pre > NOISE_CUTOFF {
128 break Some(iter_count);
129 } else if let Some(c) = iter_count.checked_mul(ITER_COUNT_MUL) {
130 iter_count = c;
131 } else {
132 // This should almost never happen, but maybe..?
133 eprintln!(
134 "WARNING: Running nearly usize::MAX iterations of test {t_name_normal}"
135 );
136 break Some(iter_count);
137 }
138 }
139 };
140
141 // Now profile!
142 let mut perf_cmd = Command::new("hyperfine");
143 // Warm up the cache and print markdown output to stdout.
144 perf_cmd.args([
145 "--style",
146 "none",
147 "--warmup",
148 "1",
149 "--export-markdown",
150 "-",
151 &format!("{test_bin} {t_name}"),
152 ]);
153 if let Some(final_iter_count) = final_iter_count {
154 perf_cmd.env(ITER_ENV_VAR, format!("{final_iter_count}"));
155 }
156 let p_out = perf_cmd.output().unwrap();
157 let fin_iter = match final_iter_count {
158 Some(i) => &format!("{i}"),
159 None => "(preset)",
160 };
161 if p_out.status.success() {
162 let output = String::from_utf8_lossy(&p_out.stdout);
163 // Strip the name of the test binary from the table (and the space after it!)
164 // + our extraneous test bits + the "Relative" column (which is always at the end and "1.00").
165 let output = output
166 .replace(&format!("{test_bin} "), "")
167 .replace(SUF_FIXED, "")
168 .replace(SUF_NORMAL, "")
169 .replace(" 1.00 |", "");
170 // Can't use .last() since we have a trailing newline. Sigh.
171 let fin = output.lines().nth(3).unwrap();
172
173 // Calculate how many iterations this does per second, for easy comparison.
174 let ms = fin
175 .split_whitespace()
176 .nth(3)
177 .unwrap()
178 .parse::<f64>()
179 .unwrap();
180 let mul_fac = 1000.0 / ms;
181 let iter_sec = match final_iter_count {
182 #[allow(clippy::cast_precision_loss)]
183 Some(c) => &format!("{:.1}", mul_fac * c as f64),
184 None => "(unknown)",
185 };
186 println!("{fin} {fin_iter} | {iter_sec} |");
187 } else {
188 println!("{t_name_normal} (ERRORED) | N/A | N/A | N/A | {fin_iter} | N/A |");
189 }
190 }
191}