diff --git a/common/perf.rs b/common/perf.rs index 017f77e5e..284022d7d 100644 --- a/common/perf.rs +++ b/common/perf.rs @@ -2,6 +2,7 @@ // Counter is used to collect statistics. +use std::io::Write; use std::sync::atomic::{AtomicBool, Ordering}; use std::sync::{Arc, Mutex, Once}; use std::time::Instant; @@ -171,7 +172,8 @@ impl Timers { Self { records: Some(Arc::new(Mutex::new(Vec::new()))) } } - /// Skips clock reads, system calls and shared recording when --perf is off. + /// Skips clock reads, system calls and shared recording when --perf (or + /// the Mach-O linker's -print_statistics) is off. pub fn disabled() -> Self { Self { records: None } } @@ -217,7 +219,10 @@ impl Timers { } } - pub fn print(&self) { + /// Prints the timer tree to `out`: stdout for the ELF linker, as C++ + /// mold does, and stderr for the Mach-O linker, where ld64 reports its + /// -print_statistics figures. + pub fn print(&self, out: &mut dyn Write) { let Some(records) = &self.records else { return; }; @@ -230,10 +235,11 @@ impl Timers { } nest_records(&mut records); - fn print_rec(records: &[Record], i: usize, indent: usize) { + fn print_rec(out: &mut dyn Write, records: &[Record], i: usize, indent: usize) { let r = &records[i]; let real = r.end.unwrap().duration_since(r.start).as_secs_f64(); - println!( + let _ = writeln!( + out, " {:8.3} {:8.3} {:8.3} {}{}", r.user, r.sys, @@ -243,14 +249,14 @@ impl Timers { ); // nest_records adds children in their recorded start order. for &child in &r.children { - print_rec(records, child, indent + 1); + print_rec(out, records, child, indent + 1); } } - println!(" User System Real Name"); + let _ = writeln!(out, " User System Real Name"); for i in 0..records.len() { if records[i].parent.is_none() { - print_rec(&records, i, 0); + print_rec(out, &records, i, 0); } } } diff --git a/elf/driver.rs b/elf/driver.rs index 9d6e7a9ab..17f294a08 100644 --- a/elf/driver.rs +++ b/elf/driver.rs @@ -610,7 +610,7 @@ pub fn link(cmdline: Cmdline) -> LinkResult { passes::show_stats(&ctx); } if ctx.args.perf { - ctx.timers.print(); + ctx.timers.print(&mut std::io::stdout()); } let _ = std::io::Write::flush(&mut std::io::stdout()); diff --git a/elf/relocatable.rs b/elf/relocatable.rs index 7d4c47ea0..cb8c69597 100644 --- a/elf/relocatable.rs +++ b/elf/relocatable.rs @@ -241,7 +241,7 @@ pub fn combine_objects(ctx: &mut Context) { passes::show_stats(ctx); } if ctx.args.perf { - ctx.timers.print(); + ctx.timers.print(&mut std::io::stdout()); } if ctx.args.quick_exit { mold_common::error::exit_after_cleanup(0); diff --git a/macho/context.rs b/macho/context.rs index 796b58e14..f3f25df38 100644 --- a/macho/context.rs +++ b/macho/context.rs @@ -3,6 +3,8 @@ use std::marker::PhantomData; +use mold_common::perf::{Timer, Timers}; + use crate::arch::Target; use crate::chunks::bind_info::BindInfoSection; use crate::chunks::chain_starts::ChainStartsSection; @@ -41,7 +43,6 @@ use crate::chunks::{ use crate::cmdline::Args; use crate::input_files::{DylibFile, FileId, ObjectFile}; use crate::symbol::{SymbolId, SymbolTable}; -use crate::util::perf::Timers; // Keep immutable and mutable chunk lookup in the same static match. macro_rules! chunk_header { @@ -339,7 +340,7 @@ impl Context { } /// Starts a -print_statistics timer for a pass. - pub fn timer(&self, name: &str) -> crate::util::perf::Timer { + pub fn timer(&self, name: &str) -> Timer { self.timers.start(name) } diff --git a/macho/passes.rs b/macho/passes.rs index 63684b1df..2c9cacd39 100644 --- a/macho/passes.rs +++ b/macho/passes.rs @@ -5386,7 +5386,7 @@ pub fn compute_uuid( /// stderr; ours reports the pass timers and the sizes that drive them. pub fn show_stats(ctx: &Context) { if ctx.args.perf { - ctx.timers.print(); + ctx.timers.print(&mut std::io::stderr()); eprintln!( " objects: {} alive of {}; dylibs: {}; output: {} bytes", ctx.objs diff --git a/macho/util/mod.rs b/macho/util/mod.rs index 4ea255639..964308722 100644 --- a/macho/util/mod.rs +++ b/macho/util/mod.rs @@ -3,7 +3,6 @@ pub(crate) mod cityhash; pub mod demangle; pub mod glob; -pub mod perf; pub(crate) mod siphash; pub(crate) mod worker_local; diff --git a/macho/util/perf.rs b/macho/util/perf.rs deleted file mode 100644 index cfd72c54d..000000000 --- a/macho/util/perf.rs +++ /dev/null @@ -1,248 +0,0 @@ -//! Wall-clock and CPU time accounting for the passes of a link. - -use std::sync::{Arc, Mutex}; -use std::time::Instant; - -#[derive(Debug)] -struct Record { - name: String, - start: Instant, - end: Option, - user_start: f64, - sys_start: f64, - user: f64, - sys: f64, - parent: Option, - children: Vec, -} - -// Infer implicit parents from complete intervals, as C++ mold does. Overlapping -// timers need not be nested, and explicitly named parents take precedence. -fn nest_records(records: &mut [Record]) { - for record in records.iter_mut() { - record.children.clear(); - } - for i in 0..records.len() { - if records[i].parent.is_none() { - let inner = &records[i]; - records[i].parent = records[..i].iter().rposition(|outer| { - outer.start <= inner.start && inner.end.unwrap() <= outer.end.unwrap() - }); - } - if let Some(parent) = records[i].parent { - records[parent].children.push(i); - } - } -} - -/// Collects wall-clock and CPU timing records for the passes of a link. -/// Cloning shares the underlying records. -#[derive(Clone, Debug)] -pub struct Timers { - records: Option>>>, -} - -/// A running timer, stopped when dropped. -pub struct Timer { - timers: Timers, - index: usize, - stopped: bool, -} - -/// A clonable handle for starting timers beneath a running timer. -#[derive(Clone)] -pub struct TimerHandle { - timers: Timers, - parent: usize, -} - -fn rusage() -> (f64, f64) { - // SAFETY: `usage` is a valid, writable rusage struct. - let mut usage: libc::rusage = unsafe { std::mem::zeroed() }; - unsafe { libc::getrusage(libc::RUSAGE_SELF, &raw mut usage) }; - let to_secs = |t: libc::timeval| t.tv_sec as f64 + t.tv_usec as f64 / 1_000_000.0; - (to_secs(usage.ru_utime), to_secs(usage.ru_stime)) -} - -impl Default for Timers { - fn default() -> Self { - Self::new() - } -} - -impl Timers { - pub fn new() -> Self { - Self { records: Some(Arc::new(Mutex::new(Vec::new()))) } - } - - /// Skips clock reads, system calls and shared recording when - /// -print_statistics is off. - pub fn disabled() -> Self { - Self { records: None } - } - - fn inactive(&self) -> Timer { - Timer { timers: self.clone(), index: 0, stopped: true } - } - - /// Starts a timer whose nesting is inferred from completed time intervals. - pub fn start(&self, name: &str) -> Timer { - self.start_child(name, None) - } - - fn start_child(&self, name: impl std::fmt::Display, parent: Option) -> Timer { - let Some(records) = &self.records else { - return self.inactive(); - }; - let (user, sys) = rusage(); - let mut records = records.lock().unwrap(); - let index = records.len(); - records.push(Record { - name: name.to_string(), - start: Instant::now(), - end: None, - user_start: user, - sys_start: sys, - user: 0.0, - sys: 0.0, - parent, - children: Vec::new(), - }); - Timer { timers: self.clone(), index, stopped: false } - } - - fn stop(&self, index: usize) { - let (user, sys) = rusage(); - let mut records = self.records.as_ref().unwrap().lock().unwrap(); - let record = &mut records[index]; - if record.end.is_none() { - record.end = Some(Instant::now()); - record.user = user - record.user_start; - record.sys = sys - record.sys_start; - } - } - - /// Prints the timer tree to stderr, where ld64 reports its - /// -print_statistics figures. - pub fn print(&self) { - let Some(records) = &self.records else { - return; - }; - let mut records = records.lock().unwrap(); - let now = Instant::now(); - for r in records.iter_mut() { - if r.end.is_none() { - r.end = Some(now); - } - } - nest_records(&mut records); - - fn print_rec(records: &[Record], i: usize, indent: usize) { - let r = &records[i]; - let real = r.end.unwrap().duration_since(r.start).as_secs_f64(); - eprintln!( - " {:8.3} {:8.3} {:8.3} {}{}", - r.user, - r.sys, - real, - " ".repeat(indent * 2), - r.name - ); - // nest_records adds children in their recorded start order. - for &child in &r.children { - print_rec(records, child, indent + 1); - } - } - - eprintln!(" User System Real Name"); - for i in 0..records.len() { - if records[i].parent.is_none() { - print_rec(&records, i, 0); - } - } - } -} - -impl Timer { - /// Starts a timer nested in this one. Timers started from parallel - /// tasks name their parent this way, since which timer started last - /// says nothing about nesting then. - pub fn child(&self, name: impl std::fmt::Display) -> Self { - self.timers.start_child(name, Some(self.index)) - } - - pub fn handle(&self) -> TimerHandle { - TimerHandle { timers: self.timers.clone(), parent: self.index } - } - - pub fn stop(&mut self) { - if !self.stopped { - self.stopped = true; - self.timers.stop(self.index); - } - } -} - -impl TimerHandle { - pub fn child(&self, name: impl std::fmt::Display) -> Timer { - self.timers.start_child(name, Some(self.parent)) - } -} - -impl Drop for Timer { - fn drop(&mut self) { - self.stop(); - } -} - -#[cfg(test)] -mod tests { - use super::*; - - #[test] - fn implicit_timer_parents_follow_completed_intervals() { - let timers = Timers::new(); - let root = timers.start("root"); - let _running = [ - timers.start("foreground"), - timers.start("nested"), - timers.start("background"), - timers.start("next foreground"), - root.child("explicit child"), - ]; - let mut records = timers.records.as_ref().unwrap().lock().unwrap(); - let start = records[0].start; - for (record, (begin, end)) in - records.iter_mut().zip([(0, 100), (10, 40), (15, 25), (20, 70), (50, 80), (60, 65)]) - { - record.start = start + std::time::Duration::from_millis(begin); - record.end = Some(start + std::time::Duration::from_millis(end)); - } - nest_records(&mut records); - let children: Vec<_> = records.iter().map(|r| r.children.clone()).collect(); - drop(records); - assert_eq!(children, [vec![1, 3, 4, 5], vec![2], vec![], vec![], vec![], vec![]]); - } - - #[test] - fn optional_recording_includes_nested_and_background_timers() { - for timers in [Timers::new(), Timers::disabled()] { - let mut root = timers.start("root"); - let child = root.child("child"); - let handle = root.handle(); - std::thread::spawn(move || drop(handle.child("background"))).join().unwrap(); - drop(child); - root.stop(); - root.stop(); - if let Some(records) = &timers.records { - let mut records = records.lock().unwrap(); - nest_records(&mut records); - assert_eq!(records.len(), 3); - assert!(records.iter().all(|record| record.end.is_some())); - assert_eq!(records[0].children, [1, 2]); - } else { - assert!(root.timers.records.is_none()); - } - } - } -}