Skip to content

Commit dba3b7f

Browse files
committed
generate profile report on all bootstrap command invocation
1 parent eb7564d commit dba3b7f

File tree

3 files changed

+50
-24
lines changed

3 files changed

+50
-24
lines changed

.gitignore

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -101,4 +101,4 @@ tests/rustdoc-gui/src/**.lock
101101
flake.lock
102102
/default.nix
103103

104-
# Before adding new lines, see the comment at the top.
104+
# Before adding new lines, see the comment at the top.

src/bootstrap/src/bin/main.rs

Lines changed: 6 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -96,7 +96,8 @@ fn main() {
9696
let out_dir = config.out.clone();
9797

9898
debug!("creating new build based on config");
99-
Build::new(config).build();
99+
let mut build = Build::new(config);
100+
build.build();
100101

101102
if suggest_setup {
102103
println!("WARNING: you have not made a `bootstrap.toml`");
@@ -147,6 +148,10 @@ fn main() {
147148
t!(file.write_all(lines.join("\n").as_bytes()));
148149
}
149150
}
151+
152+
if env::var("BOOTSTRAP_PROFILE").is_ok_and(|v| v == "1") {
153+
build.report_summary();
154+
}
150155
}
151156

152157
fn check_version(config: &Config) -> Option<String> {

src/bootstrap/src/utils/exec.rs

Lines changed: 43 additions & 22 deletions
Original file line numberDiff line numberDiff line change
@@ -20,7 +20,7 @@ use std::process::{
2020
Child, ChildStderr, ChildStdout, Command, CommandArgs, CommandEnvs, ExitStatus, Output, Stdio,
2121
};
2222
use std::sync::{Arc, Mutex};
23-
use std::time::{Duration, Instant};
23+
use std::time::{Duration, Instant, SystemTime, UNIX_EPOCH};
2424

2525
use build_helper::ci::CiEnv;
2626
use build_helper::drop_bomb::DropBomb;
@@ -74,7 +74,16 @@ pub struct CommandFingerprint {
7474
args: Vec<OsString>,
7575
envs: Vec<(OsString, Option<OsString>)>,
7676
cwd: Option<PathBuf>,
77-
short_cmd: String,
77+
}
78+
79+
impl FormatShortCmd for CommandFingerprint {
80+
fn format_short_cmd(&self) -> String {
81+
let program = Path::new(&self.program);
82+
let mut line = vec![program.file_name().unwrap().to_str().unwrap().to_owned()];
83+
line.extend(self.args.iter().map(|arg| arg.to_string_lossy().into_owned()));
84+
line.extend(self.cwd.iter().map(|p| p.to_string_lossy().into_owned()));
85+
line.join(" ")
86+
}
7887
}
7988

8089
#[derive(Default, Clone)]
@@ -92,15 +101,15 @@ impl CommandProfiler {
92101
let mut stats = self.stats.lock().unwrap();
93102
let entry = stats.entry(key).or_default();
94103
entry.traces.push(ExecutionTrace::Executed {
95-
timestamp: start_time,
104+
timestamp: SystemTime::now(),
96105
duration: start_time.elapsed(),
97106
});
98107
}
99108

100109
pub fn record_cache_hit(&self, key: CommandFingerprint) {
101110
let mut stats = self.stats.lock().unwrap();
102111
let entry = stats.entry(key).or_default();
103-
entry.traces.push(ExecutionTrace::CacheHit { timestamp: Instant::now() });
112+
entry.traces.push(ExecutionTrace::CacheHit { timestamp: SystemTime::now() });
104113
}
105114

106115
pub fn report_summary(&self) {
@@ -118,36 +127,48 @@ impl CommandProfiler {
118127
let mut writer = BufWriter::new(file);
119128
let stats = self.stats.lock().unwrap();
120129

121-
for (key, profile) in stats.iter() {
122-
writeln!(writer, "Command: {:?}", key.short_cmd).unwrap();
130+
let mut entries: Vec<_> = stats
131+
.iter()
132+
.map(|(key, profile)| {
133+
let max_duration = profile
134+
.traces
135+
.iter()
136+
.filter_map(|trace| match trace {
137+
ExecutionTrace::Executed { duration, .. } => Some(*duration),
138+
_ => None,
139+
})
140+
.max();
141+
142+
(key, profile, max_duration)
143+
})
144+
.collect();
145+
146+
entries.sort_by(|a, b| b.2.cmp(&a.2));
147+
148+
for (key, profile, max_duration) in entries {
149+
writeln!(writer, "Command: {:?}", key.format_short_cmd()).unwrap();
123150

124151
let mut hits = 0;
125152
let mut runs = 0;
126-
let mut max_duration: Option<Duration> = None;
127153

128154
for trace in &profile.traces {
129155
match trace {
130156
ExecutionTrace::CacheHit { timestamp } => {
131157
hits += 1;
132-
writeln!(writer, " - Cache hit at: {:?}", timestamp).unwrap();
158+
let time = timestamp.duration_since(UNIX_EPOCH).unwrap();
159+
writeln!(writer, " - Cache hit at: {time:?}").unwrap();
133160
}
134161
ExecutionTrace::Executed { duration, timestamp } => {
135162
runs += 1;
136-
if max_duration.is_none_or(|d| *duration > d) {
137-
max_duration = Some(*duration);
138-
}
139-
writeln!(
140-
writer,
141-
" - Executed at: {:?}, duration: {:.2?}",
142-
timestamp, duration
143-
)
144-
.unwrap();
163+
let time = timestamp.duration_since(UNIX_EPOCH).unwrap();
164+
writeln!(writer, " - Executed at: {time:?}, duration: {duration:.2?}")
165+
.unwrap();
145166
}
146167
}
147168
}
148169

149170
let duration_str = match max_duration {
150-
Some(d) => format!("{:.2?}", d),
171+
Some(d) => format!("{d:.2?}"),
151172
None => "-".into(),
152173
};
153174

@@ -158,15 +179,14 @@ impl CommandProfiler {
158179
.unwrap();
159180
}
160181

161-
// Print a message to user
162182
println!("Command profiler report saved to {filename}");
163183
}
164184
}
165185

166186
#[derive(Clone)]
167187
pub enum ExecutionTrace {
168-
CacheHit { timestamp: Instant },
169-
Executed { timestamp: Instant, duration: Duration },
188+
CacheHit { timestamp: SystemTime },
189+
Executed { timestamp: SystemTime, duration: Duration },
170190
}
171191

172192
/// Wrapper around `std::process::Command`.
@@ -351,7 +371,6 @@ impl<'a> BootstrapCommand {
351371
.map(|(k, v)| (k.to_os_string(), v.map(|val| val.to_os_string())))
352372
.collect(),
353373
cwd: command.get_current_dir().map(Path::to_path_buf),
354-
short_cmd: command.format_short_cmd(),
355374
}
356375
}
357376
}
@@ -501,12 +520,14 @@ pub trait FormatShortCmd {
501520
fn format_short_cmd(&self) -> String;
502521
}
503522

523+
#[cfg(feature = "tracing")]
504524
impl FormatShortCmd for BootstrapCommand {
505525
fn format_short_cmd(&self) -> String {
506526
self.command.format_short_cmd()
507527
}
508528
}
509529

530+
#[cfg(feature = "tracing")]
510531
impl FormatShortCmd for Command {
511532
fn format_short_cmd(&self) -> String {
512533
let program = Path::new(self.get_program());

0 commit comments

Comments
 (0)