Auto merge of #7581 - connorimes:power-profiling, r=larsbergstrom

Add energy monitoring and characterization scripts

Add the energy-profiling feature.  Users can compile the proper (or their own) version of energymon libraries to capture power/energy data at runtime.  The results are accessed through heartbeats.

Additionally, there are a couple of python scripts to enable heartbeats for profiler categories and process the results into some visualizations to help understand how time and energy is being spent in Servo.

<!-- Reviewable:start -->
[<img src="https://reviewable.io/review_button.png" height=40 alt="Review on Reviewable"/>](https://reviewable.io/reviews/servo/servo/7581)
<!-- Reviewable:end -->

ORGANIZATION.md

@@ -33,6 +33,7 @@ special integration:
 * [`tests/ref`][tests/ref]: Reference tests.
 * [`tests/html`][tests/html]: Manual test cases and examples.
 * [`tests/power`][tests/power]: Tests for measuring power usage.
+* [`tests/heartbeats`][tests/heartbeats]: Tests for profiler-level timing and energy behavior.
 * [`tests/wpt`][tests/wpt]: Web platform tests and harness.
 
 ## Miscellaneous

components/profile/heartbeats.rs

@@ -51,6 +51,7 @@ pub fn init() {
     maybe_create_heartbeat(&mut hbs, ProfilerCategory::ScriptWebSocketEvent);
     maybe_create_heartbeat(&mut hbs, ProfilerCategory::ScriptWorkerEvent);
     maybe_create_heartbeat(&mut hbs, ProfilerCategory::ScriptXhrEvent);
+    maybe_create_heartbeat(&mut hbs, ProfilerCategory::ApplicationHeartbeat);
     unsafe {
         HBS = Some(mem::transmute(Box::new(hbs)));
     }
@@ -71,6 +72,12 @@ pub fn cleanup() {
     }
 }
 
+pub fn is_heartbeat_enabled(category: &ProfilerCategory) -> bool {
+    unsafe {
+        HBS.map_or(false, |m| (*m).contains_key(category))
+    }
+}
+
 /// Issue a heartbeat (if one exists) for the given category
 pub fn maybe_heartbeat(category: &ProfilerCategory,
                        start_time: u64,

components/profile/time.rs

@@ -6,12 +6,14 @@
 
 use heartbeats;
 use ipc_channel::ipc::{self, IpcReceiver};
+use profile_traits::energy::{energy_interval_ms, read_energy_uj};
 use profile_traits::time::{ProfilerCategory, ProfilerChan, ProfilerMsg, TimerMetadata};
 use std::borrow::ToOwned;
 use std::cmp::Ordering;
 use std::collections::BTreeMap;
 use std::f64;
 use std::thread::sleep_ms;
+use std_time::precise_time_ns;
 use util::task::spawn_named;
 
 pub trait Formattable {
@@ -93,6 +95,7 @@ impl Formattable for ProfilerCategory {
             ProfilerCategory::ScriptWebSocketEvent => "Script Web Socket Event",
             ProfilerCategory::ScriptWorkerEvent => "Script Worker Event",
             ProfilerCategory::ScriptXhrEvent => "Script Xhr Event",
+            ProfilerCategory::ApplicationHeartbeat => "Application Heartbeat",
         };
         format!("{}{}", padding, name)
     }
@@ -141,8 +144,49 @@ impl Profiler {
             }
         }
         heartbeats::init();
+        let profiler_chan = ProfilerChan(chan);
 
-        ProfilerChan(chan)
+        // only spawn the application-level profiler thread if its heartbeat is enabled
+        let run_ap_thread = || {
+            heartbeats::is_heartbeat_enabled(&ProfilerCategory::ApplicationHeartbeat)
+        };
+        if run_ap_thread() {
+            let profiler_chan = profiler_chan.clone();
+            // min of 1 heartbeat/sec, max of 20 should provide accurate enough power/energy readings
+            // waking up more frequently allows the thread to end faster on exit
+            const SLEEP_MS: u32 = 10;
+            const MIN_ENERGY_INTERVAL_MS: u32 = 50;
+            const MAX_ENERGY_INTERVAL_MS: u32 = 1000;
+            let interval_ms = enforce_range(MIN_ENERGY_INTERVAL_MS, MAX_ENERGY_INTERVAL_MS, energy_interval_ms());
+            let loop_count: u32 = (interval_ms as f32 / SLEEP_MS as f32).ceil() as u32;
+            spawn_named("Application heartbeat profiler".to_owned(), move || {
+                let mut start_time = precise_time_ns();
+                let mut start_energy = read_energy_uj();
+                loop {
+                    for _ in 0..loop_count {
+                        match run_ap_thread() {
+                            true => sleep_ms(SLEEP_MS),
+                            false => return,
+                        }
+                    }
+                    let end_time = precise_time_ns();
+                    let end_energy = read_energy_uj();
+                    // send using the inner channel
+                    // (using ProfilerChan.send() forces an unwrap and sometimes panics for this background profiler)
+                    let ProfilerChan(ref c) = profiler_chan;
+                    match c.send(ProfilerMsg::Time((ProfilerCategory::ApplicationHeartbeat, None),
+                                                   (start_time, end_time),
+                                                   (start_energy, end_energy))) {
+                        Ok(_) => {},
+                        Err(_) => return,
+                    };
+                    start_time = end_time;
+                    start_energy = end_energy;
+                }
+            });
+        }
+
+        profiler_chan
     }
 
     pub fn new(port: IpcReceiver<ProfilerMsg>) -> Profiler {
@@ -178,8 +222,8 @@ impl Profiler {
 
     fn handle_msg(&mut self, msg: ProfilerMsg) -> bool {
         match msg.clone() {
-            ProfilerMsg::Time(k, t) => {
-                heartbeats::maybe_heartbeat(&k.0, t.0, t.1, 0, 0);
+            ProfilerMsg::Time(k, t, e) => {
+                heartbeats::maybe_heartbeat(&k.0, t.0, t.1, e.0, e.1);
                 let ms = (t.1 - t.0) as f64 / 1000000f64;
                 self.find_or_insert(k, ms);
             },
@@ -224,3 +268,16 @@ impl Profiler {
         println!("");
     }
 }
+
+fn enforce_range<T>(min: T, max: T, value: T) -> T where T: Ord {
+    assert!(min <= max);
+    match value.cmp(&max) {
+        Ordering::Equal | Ordering::Greater => max,
+        Ordering::Less => {
+            match value.cmp(&min) {
+                Ordering::Equal | Ordering::Less => min,
+                Ordering::Greater => value,
+            }
+        },
+    }
+}

components/profile_traits/Cargo.toml

@@ -7,13 +7,25 @@ authors = ["The Servo Project Developers"]
 name = "profile_traits"
 path = "lib.rs"
 
+[features]
+energy-profiling = ["energymon", "energy-monitor"]
+
 [dependencies.ipc-channel]
 git = "https://github.com/pcwalton/ipc-channel"
 
 [dependencies.url]
 version = "0.2"
 features = [ "serde_serialization" ]
 
+[dependencies.energymon]
+git = "https://github.com/energymon/energymon-rust.git"
+rev = "67f74732ac"
+optional = true
+
+[dependencies.energy-monitor]
+version = "0.1.0"
+optional = true
+
 [dependencies]
 serde = "0.5"
 serde_macros = "0.5"

components/profile_traits/energy.rs

@@ -0,0 +1,63 @@
+/* This Source Code Form is subject to the terms of the Mozilla Public
+ * License, v. 2.0. If a copy of the MPL was not distributed with this
+ * file, You can obtain one at http://mozilla.org/MPL/2.0/. */
+
+
+#[cfg(feature = "energy-profiling")]
+pub fn read_energy_uj() -> u64 {
+    energymon::read_energy_uj()
+}
+
+#[cfg(not(feature = "energy-profiling"))]
+pub fn read_energy_uj() -> u64 {
+    0
+}
+
+#[cfg(feature = "energy-profiling")]
+pub fn energy_interval_ms() -> u32 {
+    energymon::get_min_interval_ms()
+}
+
+#[cfg(not(feature = "energy-profiling"))]
+pub fn energy_interval_ms() -> u32 {
+    1000
+}
+
+#[cfg(feature = "energy-profiling")]
+mod energymon {
+    extern crate energymon;
+    extern crate energy_monitor;
+
+    use self::energy_monitor::EnergyMonitor;
+    use self::energymon::EnergyMon;
+    use std::mem;
+    use std::sync::{Once, ONCE_INIT};
+
+
+    static mut EM: Option<*mut EnergyMon> = None;
+
+    /// Read energy from the energy monitor, otherwise return 0.
+    pub fn read_energy_uj() -> u64 {
+        static ONCE: Once = ONCE_INIT;
+        ONCE.call_once(|| {
+            if let Ok(em) = EnergyMon::new() {
+                println!("Started energy monitoring from: {}", em.source());
+                unsafe {
+                    EM = Some(mem::transmute(Box::new(em)));
+                }
+            }
+        });
+
+        unsafe {
+            // EnergyMon implementations of EnergyMonitor always return a value
+            EM.map_or(0, |em| (*em).read_uj().unwrap())
+        }
+    }
+
+    pub fn get_min_interval_ms() -> u32 {
+        unsafe {
+            EM.map_or(0, |em| ((*em).interval_us() as f64 / 1000.0).ceil() as u32)
+        }
+    }
+
+}

components/profile_traits/lib.rs

@@ -13,6 +13,7 @@
 extern crate ipc_channel;
 extern crate serde;
 
+pub mod energy;
 pub mod mem;
 pub mod time;
 

components/profile_traits/time.rs

@@ -5,6 +5,7 @@
 extern crate time as std_time;
 extern crate url;
 
+use energy::read_energy_uj;
 use ipc_channel::ipc::IpcSender;
 use self::std_time::precise_time_ns;
 use self::url::Url;
@@ -29,7 +30,7 @@ impl ProfilerChan {
 #[derive(Clone, Deserialize, Serialize)]
 pub enum ProfilerMsg {
     /// Normal message used for reporting time
-    Time((ProfilerCategory, Option<TimerMetadata>), (u64, u64)),
+    Time((ProfilerCategory, Option<TimerMetadata>), (u64, u64), (u64, u64)),
     /// Message used to force print the profiling metrics
     Print,
     /// Tells the profiler to shut down.
@@ -72,6 +73,7 @@ pub enum ProfilerCategory {
     ScriptWebSocketEvent,
     ScriptWorkerEvent,
     ScriptXhrEvent,
+    ApplicationHeartbeat,
 }
 
 #[derive(Eq, PartialEq)]
@@ -96,15 +98,19 @@ pub fn profile<T, F>(category: ProfilerCategory,
                   -> T
     where F: FnOnce() -> T
 {
+    let start_energy = read_energy_uj();
     let start_time = precise_time_ns();
     let val = callback();
     let end_time = precise_time_ns();
+    let end_energy = read_energy_uj();
     let meta = meta.map(|(url, iframe, reflow_type)|
         TimerMetadata {
             url: url.serialize(),
             iframe: iframe == TimerMetadataFrameType::IFrame,
             incremental: reflow_type == TimerMetadataReflowType::Incremental,
         });
-    profiler_chan.send(ProfilerMsg::Time((category, meta), (start_time, end_time)));
+    profiler_chan.send(ProfilerMsg::Time((category, meta),
+                                         (start_time, end_time),
+                                         (start_energy, end_energy)));
     return val;
 }

components/servo/Cargo.toml

@@ -45,6 +45,7 @@ default = ["glutin_app", "window", "webdriver"]
 window = ["glutin_app/window"]
 headless = ["glutin_app/headless"]
 webdriver = ["webdriver_server"]
+energy-profiling = ["profile_traits/energy-profiling"]
 
 # Uncomment to profile on Linux:
 #