Support measuring process-wide perf events

Cargo.toml

@@ -33,7 +33,7 @@ atomic-traits = "0.2.0"
 atomic = "0.4.6"
 spin = "0.5.2"
 env_logger = "0.8.2"
-pfm = {version = "0.0.7", optional = true}
+pfm = {version = "0.0.8", optional = true}
 
 [dev-dependencies]
 crossbeam = "0.7.3"

src/memory_manager.rs

@@ -50,6 +50,23 @@ pub fn gc_init<VM: VMBinding>(mmtk: &'static mut MMTK<VM>, heap_size: usize) {
             "MMTk failed to initialize the logger. Possibly a logger has been initialized by user."
         ),
     }
+    #[cfg(feature = "perf_counter")]
+    {
+        use std::fs::File;
+        use std::io::Read;
+        let mut status = File::open("/proc/self/status").unwrap();
+        let mut contents = String::new();
+        status.read_to_string(&mut contents).unwrap();
+        for line in contents.lines() {
+            let split: Vec<&str> = line.split('\t').collect();
+            if split[0] == "Threads:" {
+                let threads = split[1].parse::<i32>().unwrap();
+                if threads != 1 {
+                    warn!("Current process has {} threads, process-wide perf event measurement will only include child threads spawned from this threadas", threads);
+                }
+            }
+        }
+    }
     assert!(heap_size > 0, "Invalid heap size");
     mmtk.plan
         .gc_init(heap_size, &crate::VM_MAP, &mmtk.scheduler);

src/plan/global.rs

@@ -411,7 +411,7 @@ impl<VM: VMBinding> BasePlan<VM> {
         constraints: &'static PlanConstraints,
         global_side_metadata_specs: Vec<SideMetadataSpec>,
     ) -> BasePlan<VM> {
-        let stats = Stats::new();
+        let stats = Stats::new(options.clone());
         // Initializing the analysis manager and routines
         #[cfg(feature = "analysis")]
         let analysis_manager = AnalysisManager::new(&stats);

src/scheduler/stat.rs

@@ -242,7 +242,7 @@ impl<VM: VMBinding> HasCounterSet for MMTK<VM> {
     fn counter_set(mmtk: &'static Self) -> Vec<Box<dyn WorkCounter>> {
         let mut counters: Vec<Box<dyn WorkCounter>> = vec![Box::new(WorkDuration::new())];
         #[cfg(feature = "perf_counter")]
-        for e in &mmtk.options.perf_events.events {
+        for e in &mmtk.options.work_perf_events.events {
             counters.push(box WorkPerfEvent::new(&e.0, e.1, e.2));
         }
         counters

src/scheduler/work_counter.rs

@@ -163,7 +163,7 @@ mod perf_event {
         /// -1, 0 measures all threads on CPU 0
         /// -1, -1 is invalid
         pub fn new(name: &str, pid: pid_t, cpu: c_int) -> WorkPerfEvent {
-            let mut pe = PerfEvent::new(name)
+            let mut pe = PerfEvent::new(name, false)
                 .unwrap_or_else(|_| panic!("Failed to create perf event {}", name));
             pe.open(pid, cpu)
                 .unwrap_or_else(|_| panic!("Failed to open perf event {}", name));

src/util/options.rs

@@ -189,7 +189,8 @@ options! {
     // Perf events to measure
     // Semicolons are used to separate events
     // Each event is in the format of event_name,pid,cpu (see man perf_event_open for what pid and cpu mean)
-    perf_events:           PerfEventOptions     [always_valid] = PerfEventOptions {events: vec![]}
+    work_perf_events:       PerfEventOptions     [always_valid] = PerfEventOptions {events: vec![]},
+    perf_events:            PerfEventOptions     [always_valid] = PerfEventOptions {events: vec![]}
 }
 
 impl Options {

src/util/statistics/counter/long_counter.rs

@@ -8,6 +8,7 @@ pub struct LongCounter<T: Diffable> {
     pub implicitly_start: bool,
     merge_phases: bool,
     count: Box<[u64; MAX_PHASES]>, // FIXME make this resizable
+    diffable: T,
     start_value: Option<T::Val>,
     total_count: u64,
     running: bool,
@@ -27,7 +28,7 @@ impl<T: Diffable> Counter for LongCounter<T> {
         }
         debug_assert!(!self.running);
         self.running = true;
-        self.start_value = Some(T::current_value());
+        self.start_value = Some(self.diffable.current_value());
     }
 
     fn stop(&mut self) {
@@ -36,15 +37,18 @@ impl<T: Diffable> Counter for LongCounter<T> {
         }
         debug_assert!(self.running);
         self.running = false;
-        let delta = T::diff(&T::current_value(), self.start_value.as_ref().unwrap());
+        let current_value = self.diffable.current_value();
+        let delta = self
+            .diffable
+            .diff(&current_value, self.start_value.as_ref().unwrap());
         self.count[self.stats.get_phase()] += delta;
         self.total_count += delta;
     }
 
     fn phase_change(&mut self, old_phase: usize) {
         if self.running {
-            let now = T::current_value();
-            let delta = T::diff(&now, self.start_value.as_ref().unwrap());
+            let now = self.diffable.current_value();
+            let delta = self.diffable.diff(&now, self.start_value.as_ref().unwrap());
             self.count[old_phase] += delta;
             self.total_count += delta;
             self.start_value = Some(now);
@@ -125,12 +129,14 @@ impl<T: Diffable> LongCounter<T> {
         stats: Arc<SharedStats>,
         implicitly_start: bool,
         merge_phases: bool,
+        diffable: T,
     ) -> Self {
         LongCounter {
             name,
             implicitly_start,
             merge_phases,
             count: box [0; MAX_PHASES],
+            diffable,
             start_value: None,
             total_count: 0,
             running: false,

src/util/statistics/counter/mod.rs

@@ -2,10 +2,14 @@ use std::time::Instant;
 
 mod event_counter;
 mod long_counter;
+#[cfg(feature = "perf_counter")]
+mod perf_event;
 mod size_counter;
 
 pub use self::event_counter::EventCounter;
 pub use self::long_counter::{LongCounter, Timer};
+#[cfg(feature = "perf_counter")]
+pub use self::perf_event::PerfEventDiffable;
 pub use self::size_counter::SizeCounter;
 
 pub trait Counter {
@@ -22,10 +26,12 @@ pub trait Counter {
     fn name(&self) -> &String;
 }
 
+/// A Diffable object could be stateless (e.g. a timer that reads the wall
+/// clock), or stateful (e.g. holds reference to a perf event fd)
 pub trait Diffable {
     type Val;
-    fn current_value() -> Self::Val;
-    fn diff(current: &Self::Val, earlier: &Self::Val) -> u64;
+    fn current_value(&mut self) -> Self::Val;
+    fn diff(&mut self, current: &Self::Val, earlier: &Self::Val) -> u64;
     fn print_diff(val: u64);
 }
 
@@ -34,11 +40,11 @@ pub struct MonotoneNanoTime;
 impl Diffable for MonotoneNanoTime {
     type Val = Instant;
 
-    fn current_value() -> Instant {
+    fn current_value(&mut self) -> Instant {
         Instant::now()
     }
 
-    fn diff(current: &Instant, earlier: &Instant) -> u64 {
+    fn diff(&mut self, current: &Instant, earlier: &Instant) -> u64 {
         let delta = current.duration_since(*earlier);
         delta.as_secs() * 1_000_000_000 + u64::from(delta.subsec_nanos())
     }

src/util/statistics/counter/perf_event.rs

@@ -0,0 +1,41 @@
+use super::Diffable;
+use pfm::{PerfEvent, PerfEventValue};
+
+/// A [`Diffable`] helper type for measuring overall perf events for mutators
+/// and GC
+/// This is the process-wide counterpart of [`crate::scheduler::work_counter::WorkPerfEvent`].
+pub struct PerfEventDiffable {
+    pe: PerfEvent,
+}
+
+impl PerfEventDiffable {
+    pub fn new(name: &str) -> Self {
+        let mut pe = PerfEvent::new(name, true)
+            .unwrap_or_else(|_| panic!("Failed to create perf event {}", name));
+        // measures the calling thread (and all child threads) on all CPUs
+        pe.open(0, -1)
+            .unwrap_or_else(|_| panic!("Failed to open perf event {}", name));
+        PerfEventDiffable { pe }
+    }
+}
+
+impl Diffable for PerfEventDiffable {
+    type Val = PerfEventValue;
+
+    fn current_value(&mut self) -> Self::Val {
+        let val = self.pe.read().unwrap();
+        self.pe.enable();
+        self.pe.reset();
+        val
+    }
+
+    fn diff(&mut self, current: &Self::Val, _earlier: &Self::Val) -> u64 {
+        // earlier value is not used as the counter is reset after each use
+        assert_eq!(current.time_enabled, current.time_running);
+        current.value as u64
+    }
+
+    fn print_diff(val: u64) {
+        print!("{}", val);
+    }
+}

src/util/statistics/stats.rs

@@ -1,4 +1,5 @@
 use crate::mmtk::MMTK;
+use crate::util::options::UnsafeOptionsWrapper;
 use crate::util::statistics::counter::*;
 use crate::util::statistics::Timer;
 use crate::vm::VMBinding;
@@ -51,29 +52,45 @@ pub struct Stats {
 }
 
 impl Stats {
-    pub fn new() -> Self {
+    #[allow(unused)]
+    pub fn new(options: Arc<UnsafeOptionsWrapper>) -> Self {
+        #[cfg(feature = "perf_counter")]
+        let perfmon = {
+            let mut perfmon: Perfmon = Default::default();
+            perfmon.initialize().expect("Perfmon failed to initialize");
+            perfmon
+        };
         let shared = Arc::new(SharedStats {
             phase: AtomicUsize::new(0),
             gathering_stats: AtomicBool::new(false),
         });
+        let mut counters: Vec<Arc<Mutex<dyn Counter + Send>>> = vec![];
         let t = Arc::new(Mutex::new(LongCounter::new(
             "time".to_string(),
             shared.clone(),
             true,
             false,
+            MonotoneNanoTime {},
         )));
+        counters.push(t.clone());
+        #[cfg(feature = "perf_counter")]
+        for e in &options.perf_events.events {
+            counters.push(Arc::new(Mutex::new(LongCounter::new(
+                e.0.clone(),
+                shared.clone(),
+                true,
+                false,
+                PerfEventDiffable::new(&e.0),
+            ))));
+        }
         Stats {
             gc_count: AtomicUsize::new(0),
-            total_time: t.clone(),
+            total_time: t,
             #[cfg(feature = "perf_counter")]
-            perfmon: {
-                let mut perfmon: Perfmon = Default::default();
-                perfmon.initialize().expect("Perfmon failed to initialize");
-                perfmon
-            },
+            perfmon,
 
             shared,
-            counters: Mutex::new(vec![t]),
+            counters: Mutex::new(counters),
             exceeded_phase_limit: AtomicBool::new(false),
         }
     }
@@ -118,6 +135,7 @@ impl Stats {
             self.shared.clone(),
             implicit_start,
             merge_phases,
+            MonotoneNanoTime {},
         )));
         guard.push(counter.clone());
         counter
@@ -237,9 +255,3 @@ impl Stats {
         self.shared.get_gathering_stats()
     }
 }
-
-impl Default for Stats {
-    fn default() -> Self {
-        Self::new()
-    }
-}