Merge pull request #3233 from rtfeldman/fix-timings

Print timings across make specialization passes
This commit is contained in:
Folkert de Vries 2022-06-17 13:39:20 +02:00 committed by GitHub
commit 3f5edaff4c
No known key found for this signature in database
GPG key ID: 4AEE18F83AFDEB23
2 changed files with 20 additions and 22 deletions

View file

@ -176,11 +176,15 @@ pub fn build_file<'a>(
"Find Specializations",
module_timing.find_specializations,
);
report_timing(
buf,
"Make Specializations",
module_timing.make_specializations,
);
let multiple_make_specializations_passes = module_timing.make_specializations.len() > 1;
for (i, pass_time) in module_timing.make_specializations.iter().enumerate() {
let suffix = if multiple_make_specializations_passes {
format!(" (Pass {})", i)
} else {
String::new()
};
report_timing(buf, &format!("Make Specializations{}", suffix), *pass_time);
}
report_timing(buf, "Other", module_timing.other());
buf.push('\n');
report_timing(buf, "Total", module_timing.total());
@ -460,16 +464,6 @@ pub fn check_file(
report_timing(buf, "Canonicalize", module_timing.canonicalize);
report_timing(buf, "Constrain", module_timing.constrain);
report_timing(buf, "Solve", module_timing.solve);
report_timing(
buf,
"Find Specializations",
module_timing.find_specializations,
);
report_timing(
buf,
"Make Specializations",
module_timing.make_specializations,
);
report_timing(buf, "Other", module_timing.other());
buf.push('\n');
report_timing(buf, "Total", module_timing.total());

View file

@ -879,7 +879,8 @@ pub struct ModuleTiming {
pub constrain: Duration,
pub solve: Duration,
pub find_specializations: Duration,
pub make_specializations: Duration,
// indexed by make specializations pass
pub make_specializations: Vec<Duration>,
// TODO pub monomorphize: Duration,
/// Total duration will always be more than the sum of the other fields, due
/// to things like state lookups in between phases, waiting on other threads, etc.
@ -897,7 +898,7 @@ impl ModuleTiming {
constrain: Duration::default(),
solve: Duration::default(),
find_specializations: Duration::default(),
make_specializations: Duration::default(),
make_specializations: Vec::with_capacity(2),
start_time,
end_time: start_time, // just for now; we'll overwrite this at the end
}
@ -923,8 +924,9 @@ impl ModuleTiming {
} = self;
let calculate = |t: Result<Duration, _>| -> Option<Duration> {
t.ok()?
.checked_sub(*make_specializations)?
make_specializations
.iter()
.fold(t.ok(), |t, pass_time| t?.checked_sub(*pass_time))?
.checked_sub(*find_specializations)?
.checked_sub(*solve)?
.checked_sub(*constrain)?
@ -4415,9 +4417,11 @@ fn make_specializations<'a>(
mono_env.home.register_debug_idents(mono_env.ident_ids);
let make_specializations_end = SystemTime::now();
module_timing.make_specializations = make_specializations_end
module_timing.make_specializations.push(
make_specializations_end
.duration_since(make_specializations_start)
.unwrap();
.unwrap(),
);
Msg::MadeSpecializations {
module_id: home,