Mirrors/servo
1
0
Fork 0
mirror of https://github.com/servo/servo.git synced 2025-08-03 04:30:10 +01:00
Code Issues Projects Releases Packages Wiki Activity

Remove support for heartbeats profiling

Browse source
This commit is contained in:
Simon Sapin 2020-06-04 14:28:02 +02:00
parent 0abe90647f
commit b282bd3a44
14 changed files with 7 additions and 1157 deletions
Download patch file Download diff file Expand all files Collapse all files

13
components/config/opts.rs
View file

@ -109,9 +109,6 @@ pub struct Opts {
/// Periodically print out on which events script threads spend their processing time.
pub profile_script_events: bool,
/// Enable all heartbeats for profiling.
pub profile_heartbeats: bool,
/// `None` to disable debugger or `Some` with a port number to start a server to listen to
/// remote Firefox debugger connections.
pub debugger_port: Option<u16>,
@ -264,9 +261,6 @@ pub struct DebugOptions {
/// Profile which events script threads spend their time on.
pub profile_script_events: bool,
/// Enable all heartbeats for profiling.
pub profile_heartbeats: bool,
/// Paint borders along fragment boundaries.
pub show_fragment_borders: bool,
@ -333,7 +327,6 @@ impl DebugOptions {
"dump-display-list-json" => self.dump_display_list_json = true,
"relayout-event" => self.relayout_event = true,
"profile-script-events" => self.profile_script_events = true,
"profile-heartbeats" => self.profile_heartbeats = true,
"show-fragment-borders" => self.show_fragment_borders = true,
"show-parallel-layout" => self.show_parallel_layout = true,
"trace-layout" => self.trace_layout = true,
@ -397,10 +390,6 @@ fn print_debug_usage(app: &str) -> ! {
"profile-script-events",
"Enable profiling of script-related events.",
);
print_option(
"profile-heartbeats",
"Enable heartbeats for all thread categories.",
);
print_option(
"show-fragment-borders",
"Paint borders along fragment boundaries.",
@ -509,7 +498,6 @@ pub fn default_opts() -> Opts {
dump_display_list_json: false,
relayout_event: false,
profile_script_events: false,
profile_heartbeats: false,
disable_share_style_cache: false,
style_sharing_stats: false,
convert_mouse_to_touch: false,
@ -896,7 +884,6 @@ pub fn from_cmdline_args(mut opts: Options, args: &[String]) -> ArgumentParsingR
hard_fail: opt_match.opt_present("f") && !opt_match.opt_present("F"),
bubble_inline_sizes_separately: bubble_inline_sizes_separately,
profile_script_events: debug_options.profile_script_events,
profile_heartbeats: debug_options.profile_heartbeats,
trace_layout: debug_options.trace_layout,
debugger_port: debugger_port,
devtools_port: devtools_port,

3
components/profile/Cargo.toml
View file

@ -11,14 +11,11 @@ name = "profile"
path = "lib.rs"
[dependencies]
heartbeats-simple = "0.4"
ipc-channel = "0.14"
log = "0.4"
profile_traits = { path = "../profile_traits" }
serde = "1.0"
serde_json = "1.0"
servo_config = { path = "../config" }
time_crate = { package = "time", version = "0.1.12" }
[target.'cfg(target_os = "macos")'.dependencies]
task_info = { path = "../../support/rust-task_info" }

64
components/profile/README.md
View file

@ -1,64 +0,0 @@
This crate hosts the Servo profiler.
Its APIs can be found in the `profile_traits` crate.
# Heartbeats
Heartbeats allow fine-grained timing and energy profiling of Servo tasks specified in the `ProfilerCategory` enum (see the `profile_traits::time` module).
When enabled, a heartbeat is issued for each profiler category event.
They also compute the average performance and power for three levels of granularity:
* Global: the entire runtime.
* Window: the category's last `N` events, where `N` is the size of a sliding window.
* Instant: the category's most recent event.
## Enabling
Heartbeats are enabled for categories by setting proper environment variables prior to launching Servo.
For each desired category, set the `SERVO_HEARTBEAT_ENABLE_MyCategory` environment variable to any value (an empty string will do) where `MyCategory` is the `ProfilerCategory` name exactly as it appears in the enum.
For example:
```
SERVO_HEARTBEAT_ENABLE_LayoutPerform=""
```
Then set the `SERVO_HEARTBEAT_LOG_MyCategory` environment variable so Servo knows where to write the results.
For example:
```
SERVO_HEARTBEAT_LOG_LayoutPerform="/tmp/heartbeat-LayoutPerform.log"
```
The target directory must already exist and be writeable.
Results are written to the log file every `N` heartbeats and when the profiler shuts down.
You can optionally specify the size of the sliding window by setting `SERVO_HEARTBEAT_WINDOW_MyCategory` to a positive integer value.
The default value is `20`.
For example:
```
SERVO_HEARTBEAT_WINDOW_LayoutPerform=20
```
The window size is also how many heartbeats will be stored in memory.
## Log Files
Log files are whitespace-delimited.
`HB` is the heartbeat number, ordered by when they are registered (not necessarily start or end time!).
The count starts at `0`.
`Tag` is a client-specified identifier for each heartbeat.
Servo does not use this, so the value is always `0`.
`Work` is the amount of work completed for a particular heartbeat and is used in computing performance.
At this time, Servo simply specifies `1` unit of work for each heartbeat.
`Time` and `Energy` have `Start` and `End` values as captured during runtime.
Time is measured in nanoseconds and energy is measured in microjoules.
`Work`, `Time`, and `Energy` also have `Global` and `Window` values which are the summed over the entire runtime and sliding window period, respectively.
`Perf` (performance) and `Pwr` (power) have `Global`, `Window`, and `Instant` values as described above.

181
components/profile/heartbeats.rs
View file

@ -1,181 +0,0 @@
/* 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 https://mozilla.org/MPL/2.0/. */
use self::synchronized_heartbeat::{heartbeat_window_callback, lock_and_work};
use heartbeats_simple::HeartbeatPow as Heartbeat;
use profile_traits::time::ProfilerCategory;
use std::collections::HashMap;
use std::env::var_os;
use std::fs::File;
use std::path::Path;
/// Initialize heartbeats
pub fn init(profile_heartbeats: bool) {
lock_and_work(|hbs_opt| {
if hbs_opt.is_none() {
let mut hbs: Box<HashMap<ProfilerCategory, Heartbeat>> = Box::new(HashMap::new());
maybe_create_heartbeat(
&mut hbs,
ProfilerCategory::ApplicationHeartbeat,
profile_heartbeats,
);
*hbs_opt = Some(Box::into_raw(hbs))
}
});
}
/// Log regmaining buffer data and cleanup heartbeats
pub fn cleanup() {
let hbs_opt_box: Option<Box<HashMap<ProfilerCategory, Heartbeat>>> = lock_and_work(|hbs_opt| {
hbs_opt
.take()
.map(|hbs_ptr| unsafe { Box::from_raw(hbs_ptr) })
});
if let Some(mut hbs) = hbs_opt_box {
for (_, v) in hbs.iter_mut() {
// log any remaining heartbeat records before dropping
log_heartbeat_records(v);
}
hbs.clear();
}
}
/// Check if a heartbeat exists for the given category
pub fn is_heartbeat_enabled(category: &ProfilerCategory, profile_heartbeats: bool) -> bool {
let is_enabled = lock_and_work(|hbs_opt| {
hbs_opt.map_or(false, |hbs_ptr| unsafe {
(*hbs_ptr).contains_key(category)
})
});
is_enabled || is_create_heartbeat(category, profile_heartbeats)
}
/// Issue a heartbeat (if one exists) for the given category
pub fn maybe_heartbeat(
category: &ProfilerCategory,
start_time: u64,
end_time: u64,
start_energy: u64,
end_energy: u64,
profile_heartbeats: bool,
) {
lock_and_work(|hbs_opt| {
if let Some(hbs_ptr) = *hbs_opt {
unsafe {
if !(*hbs_ptr).contains_key(category) {
maybe_create_heartbeat(&mut (*hbs_ptr), category.clone(), profile_heartbeats);
}
if let Some(h) = (*hbs_ptr).get_mut(category) {
(*h).heartbeat(0, 1, start_time, end_time, start_energy, end_energy);
}
}
}
});
}
// TODO(cimes): Android doesn't really do environment variables. Need a better way to configure dynamically.
fn is_create_heartbeat(category: &ProfilerCategory, profile_heartbeats: bool) -> bool {
profile_heartbeats || var_os(format!("SERVO_HEARTBEAT_ENABLE_{:?}", category)).is_some()
}
fn open_heartbeat_log<P: AsRef<Path>>(name: P) -> Option<File> {
match File::create(name) {
Ok(f) => Some(f),
Err(e) => {
warn!("Failed to open heartbeat log: {}", e);
None
},
}
}
#[cfg(target_os = "android")]
fn get_heartbeat_log(category: &ProfilerCategory) -> Option<File> {
open_heartbeat_log(format!("/sdcard/servo/heartbeat-{:?}.log", category))
}
#[cfg(not(target_os = "android"))]
fn get_heartbeat_log(category: &ProfilerCategory) -> Option<File> {
var_os(format!("SERVO_HEARTBEAT_LOG_{:?}", category)).and_then(|name| open_heartbeat_log(&name))
}
fn get_heartbeat_window_size(category: &ProfilerCategory) -> usize {
const WINDOW_SIZE_DEFAULT: usize = 1;
match var_os(format!("SERVO_HEARTBEAT_WINDOW_{:?}", category)) {
Some(w) => match w.into_string() {
Ok(s) => s.parse::<usize>().unwrap_or(WINDOW_SIZE_DEFAULT),
_ => WINDOW_SIZE_DEFAULT,
},
None => WINDOW_SIZE_DEFAULT,
}
}
/// Possibly create a heartbeat
fn maybe_create_heartbeat(
hbs: &mut HashMap<ProfilerCategory, Heartbeat>,
category: ProfilerCategory,
profile_heartbeats: bool,
) {
if is_create_heartbeat(&category, profile_heartbeats) {
// get optional log file
let logfile: Option<File> = get_heartbeat_log(&category);
// window size
let window_size: usize = get_heartbeat_window_size(&category);
// create the heartbeat
match Heartbeat::new(window_size, Some(heartbeat_window_callback), logfile) {
Ok(hb) => {
debug!("Created heartbeat for {:?}", category);
hbs.insert(category, hb);
},
Err(e) => warn!("Failed to create heartbeat for {:?}: {}", category, e),
}
};
}
/// Log heartbeat records up to the buffer index
fn log_heartbeat_records(hb: &mut Heartbeat) {
match hb.log_to_buffer_index() {
Ok(_) => (),
Err(e) => warn!("Failed to write heartbeat log: {}", e),
}
}
mod synchronized_heartbeat {
use super::log_heartbeat_records;
use heartbeats_simple::HeartbeatPow as Heartbeat;
use heartbeats_simple::HeartbeatPowContext as HeartbeatContext;
use profile_traits::time::ProfilerCategory;
use std::collections::HashMap;
use std::sync::atomic::{AtomicBool, Ordering};
static mut HBS: Option<*mut HashMap<ProfilerCategory, Heartbeat>> = None;
// unfortunately can't encompass the actual hashmap in a Mutex (Heartbeat isn't Send/Sync), so we'll use a spinlock
static HBS_SPINLOCK: AtomicBool = AtomicBool::new(false);
pub fn lock_and_work<F, R>(work: F) -> R
where
F: FnOnce(&mut Option<*mut HashMap<ProfilerCategory, Heartbeat>>) -> R,
{
while HBS_SPINLOCK.compare_and_swap(false, true, Ordering::SeqCst) {}
let result = unsafe { work(&mut HBS) };
HBS_SPINLOCK.store(false, Ordering::SeqCst);
result
}
/// Callback function used to log the window buffer.
/// When this is called from native C, the heartbeat is safely locked internally and the global lock is held.
/// If calling from this file, you must already hold the global lock!
pub extern "C" fn heartbeat_window_callback(hb: *const HeartbeatContext) {
unsafe {
if let Some(hbs_ptr) = HBS {
for (_, v) in (*hbs_ptr).iter_mut() {
if &v.hb as *const HeartbeatContext == hb {
log_heartbeat_records(v);
}
}
}
}
}
}

4
components/profile/lib.rs
View file

@ -4,15 +4,11 @@
#![deny(unsafe_code)]
#[macro_use]
extern crate log;
#[macro_use]
extern crate profile_traits;
#[macro_use]
extern crate serde;
#[allow(unsafe_code)]
mod heartbeats;
#[allow(unsafe_code)]
pub mod mem;
pub mod time;

67
components/profile/time.rs
View file

@ -4,7 +4,6 @@
//! Timing functions.
use crate::heartbeats;
use crate::trace_dump::TraceDump;
use ipc_channel::ipc::{self, IpcReceiver};
use profile_traits::time::{
@ -19,7 +18,6 @@ use std::io::{self, Write};
use std::path::Path;
use std::time::Duration;
use std::{f64, thread, u32, u64};
use time_crate::precise_time_ns;
pub trait Formattable {
fn format(&self, output: &Option<OutputOptions>) -> String;
@ -151,7 +149,6 @@ impl Formattable for ProfilerCategory {
ProfilerCategory::TimeToInteractive => "Time to Interactive",
ProfilerCategory::IpcReceiver => "Blocked at IPC Receive",
ProfilerCategory::IpcBytesReceiver => "Blocked at IPC Bytes Receive",
ProfilerCategory::ApplicationHeartbeat => "Application Heartbeat",
};
format!("{}{}", padding, name)
}
@ -167,15 +164,10 @@ pub struct Profiler {
pub last_msg: Option<ProfilerMsg>,
trace: Option<TraceDump>,
blocked_layout_queries: HashMap<String, u32>,
profile_heartbeats: bool,
}
impl Profiler {
pub fn create(
output: &Option<OutputOptions>,
file_path: Option<String>,
profile_heartbeats: bool,
) -> ProfilerChan {
pub fn create(output: &Option<OutputOptions>, file_path: Option<String>) -> ProfilerChan {
let (chan, port) = ipc::channel().unwrap();
match *output {
Some(ref option) => {
@ -185,8 +177,7 @@ impl Profiler {
.name("Time profiler".to_owned())
.spawn(move || {
let trace = file_path.as_ref().and_then(|p| TraceDump::new(p).ok());
let mut profiler =
Profiler::new(port, trace, Some(outputoption), profile_heartbeats);
let mut profiler = Profiler::new(port, trace, Some(outputoption));
profiler.start();
})
.expect("Thread spawning failed");
@ -216,7 +207,7 @@ impl Profiler {
.name("Time profiler".to_owned())
.spawn(move || {
let trace = file_path.as_ref().and_then(|p| TraceDump::new(p).ok());
let mut profiler = Profiler::new(port, trace, None, profile_heartbeats);
let mut profiler = Profiler::new(port, trace, None);
profiler.start();
})
.expect("Thread spawning failed");
@ -239,60 +230,13 @@ impl Profiler {
},
}
heartbeats::init(profile_heartbeats);
let profiler_chan = ProfilerChan(chan);
// only spawn the application-level profiler thread if its heartbeat is enabled
let run_ap_thread = move || {
heartbeats::is_heartbeat_enabled(
&ProfilerCategory::ApplicationHeartbeat,
profile_heartbeats,
)
};
if run_ap_thread() {
let profiler_chan = profiler_chan.clone();
// min of 1 heartbeat/sec, max of 20 should provide accurate enough readings
// waking up more frequently allows the thread to end faster on exit
const SLEEP_MS: u32 = 10;
let interval_ms = 200;
let loop_count: u32 = (interval_ms as f32 / SLEEP_MS as f32).ceil() as u32;
thread::Builder::new()
.name("Application heartbeat profiler".to_owned())
.spawn(move || {
let mut start_time = precise_time_ns();
loop {
for _ in 0..loop_count {
if run_ap_thread() {
thread::sleep(Duration::from_millis(SLEEP_MS as u64))
} else {
return;
}
}
let end_time = precise_time_ns();
// send using the inner channel
// (using ProfilerChan.send() forces an unwrap
// and sometimes panics for this background profiler)
let ProfilerChan(ref c) = profiler_chan;
if let Err(_) = c.send(ProfilerMsg::Time(
(ProfilerCategory::ApplicationHeartbeat, None),
(start_time, end_time),
)) {
return;
}
start_time = end_time;
}
})
.expect("Thread spawning failed");
}
profiler_chan
ProfilerChan(chan)
}
pub fn new(
port: IpcReceiver<ProfilerMsg>,
trace: Option<TraceDump>,
output: Option<OutputOptions>,
profile_heartbeats: bool,
) -> Profiler {
Profiler {
port: port,
@ -301,7 +245,6 @@ impl Profiler {
last_msg: None,
trace: trace,
blocked_layout_queries: HashMap::new(),
profile_heartbeats,
}
}
@ -320,7 +263,6 @@ 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, self.profile_heartbeats);
if let Some(ref mut trace) = self.trace {
trace.write_one(&k, t);
}
@ -346,7 +288,6 @@ impl Profiler {
*self.blocked_layout_queries.entry(url).or_insert(0) += 1;
},
ProfilerMsg::Exit(chan) => {
heartbeats::cleanup();
self.print_buckets();
let _ = chan.send(());
return false;

1
components/profile_traits/time.rs
View file

@ -110,7 +110,6 @@ pub enum ProfilerCategory {
TimeToInteractive = 0x82,
IpcReceiver = 0x83,
IpcBytesReceiver = 0x84,
ApplicationHeartbeat = 0x90,
}
#[derive(Clone, Debug, Deserialize, Eq, Ord, PartialEq, PartialOrd, Serialize)]

1
components/servo/lib.rs
View file

@ -386,7 +386,6 @@ where
let time_profiler_chan = profile_time::Profiler::create(
&opts.time_profiling,
opts.time_profiler_trace_path.clone(),
opts.profile_heartbeats,
);
let mem_profiler_chan = profile_mem::Profiler::create(opts.mem_profiler_period);