Add a sampling profiler and a script to generate profiles for use with Gecko tooling.

This commit is contained in:
Josh Matthews 2019-03-22 13:15:50 -04:00
parent db7bb2a510
commit 90f67c11e5
13 changed files with 379 additions and 28 deletions

1
Cargo.lock generated
View file

@ -158,6 +158,7 @@ dependencies = [
"mach 0.2.3 (registry+https://github.com/rust-lang/crates.io-index)",
"msg 0.0.1",
"serde 1.0.80 (registry+https://github.com/rust-lang/crates.io-index)",
"serde_json 1.0.13 (registry+https://github.com/rust-lang/crates.io-index)",
]
[[package]]

View file

@ -21,6 +21,7 @@ libc = "0.2"
log = "0.4"
msg = {path = "../msg"}
serde = "1.0.60"
serde_json = "1.0"
crossbeam-channel = "0.3"
[target.'cfg(target_os = "macos")'.dependencies]

View file

@ -2,16 +2,17 @@
* 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 crate::sampler::Sampler;
use crate::sampler::{NativeStack, Sampler};
use crossbeam_channel::{after, unbounded, Receiver, Sender};
use ipc_channel::ipc::IpcSender;
use msg::constellation_msg::MonitoredComponentId;
use msg::constellation_msg::{
BackgroundHangMonitor, BackgroundHangMonitorClone, BackgroundHangMonitorRegister,
};
use msg::constellation_msg::{HangAlert, HangAnnotation};
use msg::constellation_msg::{HangAlert, HangAnnotation, HangMonitorAlert};
use std::cell::Cell;
use std::collections::HashMap;
use std::sync::Mutex;
use std::thread;
use std::time::{Duration, Instant};
@ -20,18 +21,46 @@ pub struct HangMonitorRegister {
sender: Sender<(MonitoredComponentId, MonitoredComponentMsg)>,
}
#[derive(Copy, Clone, PartialEq)]
enum SamplerState {
NotSampling,
StartSampling(Duration),
Sampling,
Resolving,
}
lazy_static! {
static ref SAMPLING_STATE: Mutex<SamplerState> = Mutex::new(SamplerState::NotSampling);
}
impl HangMonitorRegister {
/// Start a new hang monitor worker, and return a handle to register components for monitoring.
pub fn init(constellation_chan: IpcSender<HangAlert>) -> Box<BackgroundHangMonitorRegister> {
pub fn init(
constellation_chan: IpcSender<HangMonitorAlert>,
) -> Box<BackgroundHangMonitorRegister> {
let (sender, port) = unbounded();
let _ = thread::Builder::new().spawn(move || {
let mut monitor = { BackgroundHangMonitorWorker::new(constellation_chan, port) };
let mut monitor = BackgroundHangMonitorWorker::new(constellation_chan, port);
while monitor.run() {
// Monitoring until all senders have been dropped...
}
});
Box::new(HangMonitorRegister { sender })
}
pub fn toggle(rate: Duration) {
let state = *SAMPLING_STATE.lock().unwrap();
match state {
SamplerState::NotSampling => {
println!("Starting profiler.");
*SAMPLING_STATE.lock().unwrap() = SamplerState::StartSampling(rate);
},
SamplerState::Sampling => {
println!("Stopping profiler.");
*SAMPLING_STATE.lock().unwrap() = SamplerState::Resolving;
},
_ => (),
}
}
}
impl BackgroundHangMonitorRegister for HangMonitorRegister {
@ -55,6 +84,7 @@ impl BackgroundHangMonitorRegister for HangMonitorRegister {
bhm_chan.send(MonitoredComponentMsg::Register(
sampler,
thread::current().name().map(str::to_owned),
transient_hang_timeout,
permanent_hang_timeout,
));
@ -71,7 +101,7 @@ impl BackgroundHangMonitorClone for HangMonitorRegister {
/// Messages sent from monitored components to the monitor.
pub enum MonitoredComponentMsg {
/// Register component for monitoring,
Register(Box<Sampler>, Duration, Duration),
Register(Box<Sampler>, Option<String>, Duration, Duration),
/// Unregister component for monitoring.
Unregister,
/// Notify start of new activity for a given component,
@ -138,25 +168,103 @@ struct MonitoredComponent {
is_waiting: bool,
}
struct Sample(MonitoredComponentId, Instant, NativeStack);
pub struct BackgroundHangMonitorWorker {
component_names: HashMap<MonitoredComponentId, String>,
monitored_components: HashMap<MonitoredComponentId, MonitoredComponent>,
constellation_chan: IpcSender<HangAlert>,
constellation_chan: IpcSender<HangMonitorAlert>,
port: Receiver<(MonitoredComponentId, MonitoredComponentMsg)>,
sampling_duration: Option<Duration>,
last_sample: Instant,
creation: Instant,
sampling_baseline: Instant,
samples: Vec<Sample>,
}
impl BackgroundHangMonitorWorker {
pub fn new(
constellation_chan: IpcSender<HangAlert>,
constellation_chan: IpcSender<HangMonitorAlert>,
port: Receiver<(MonitoredComponentId, MonitoredComponentMsg)>,
) -> Self {
Self {
component_names: Default::default(),
monitored_components: Default::default(),
constellation_chan,
port,
sampling_duration: None,
last_sample: Instant::now(),
sampling_baseline: Instant::now(),
creation: Instant::now(),
samples: vec![],
}
}
fn handle_sampling(&mut self) {
let state = *SAMPLING_STATE.lock().unwrap();
match state {
SamplerState::StartSampling(rate) => {
*SAMPLING_STATE.lock().unwrap() = SamplerState::Sampling;
self.sampling_duration = Some(rate);
self.sampling_baseline = Instant::now();
},
SamplerState::Resolving => {
let mut bytes = vec![];
bytes.extend(
format!(
"{{ \"rate\": {}, \"start\": {}, \"data\": [\n",
self.sampling_duration.unwrap().as_millis(),
(self.sampling_baseline - self.creation).as_millis(),
)
.as_bytes(),
);
let mut first = true;
let to_resolve = self.samples.len();
for (i, Sample(id, instant, stack)) in self.samples.drain(..).enumerate() {
println!("Resolving {}/{}", i + 1, to_resolve);
let profile = stack.to_hangprofile();
let name = match self.component_names.get(&id) {
Some(ref s) => format!("\"{}\"", s),
None => format!("null"),
};
let json = format!(
"{}{{ \"name\": {}, \"namespace\": {}, \"index\": {}, \"type\": \"{:?}\", \
\"time\": {}, \"frames\": {} }}",
if !first { ",\n" } else { "" },
name,
id.0.namespace_id.0,
id.0.index.0.get(),
id.1,
(instant - self.sampling_baseline).as_millis(),
serde_json::to_string(&profile.backtrace).unwrap(),
);
bytes.extend(json.as_bytes());
first = false;
}
bytes.extend(b"\n] }");
let _ = self
.constellation_chan
.send(HangMonitorAlert::Profile(bytes));
*SAMPLING_STATE.lock().unwrap() = SamplerState::NotSampling;
self.sampling_duration = None;
},
_ => (),
}
}
pub fn run(&mut self) -> bool {
self.handle_sampling();
let timeout = if let Some(duration) = self.sampling_duration {
duration
.checked_sub(Instant::now() - self.last_sample)
.unwrap_or_else(|| Duration::from_millis(0))
} else {
Duration::from_millis(100)
};
let received = select! {
recv(self.port) -> event => {
match event {
@ -165,7 +273,7 @@ impl BackgroundHangMonitorWorker {
Err(_) => return false,
}
},
recv(after(Duration::from_millis(100))) -> _ => None,
recv(after(timeout)) -> _ => None,
};
if let Some(msg) = received {
self.handle_msg(msg);
@ -175,7 +283,15 @@ impl BackgroundHangMonitorWorker {
self.handle_msg(another_msg);
}
}
self.perform_a_hang_monitor_checkpoint();
if let Some(duration) = self.sampling_duration {
if Instant::now() - self.last_sample > duration {
self.sample();
self.last_sample = Instant::now();
}
} else {
self.perform_a_hang_monitor_checkpoint();
}
true
}
@ -185,6 +301,7 @@ impl BackgroundHangMonitorWorker {
component_id,
MonitoredComponentMsg::Register(
sampler,
name,
transient_hang_timeout,
permanent_hang_timeout,
),
@ -199,6 +316,9 @@ impl BackgroundHangMonitorWorker {
sent_permanent_alert: false,
is_waiting: true,
};
if let Some(name) = name {
self.component_names.insert(component_id.clone(), name);
}
assert!(
self.monitored_components
.insert(component_id, component)
@ -250,11 +370,13 @@ impl BackgroundHangMonitorWorker {
Ok(native_stack) => Some(native_stack.to_hangprofile()),
Err(()) => None,
};
let _ = self.constellation_chan.send(HangAlert::Permanent(
component_id.clone(),
last_annotation,
profile,
));
let _ = self
.constellation_chan
.send(HangMonitorAlert::Hang(HangAlert::Permanent(
component_id.clone(),
last_annotation,
profile,
)));
monitored.sent_permanent_alert = true;
continue;
}
@ -264,9 +386,23 @@ impl BackgroundHangMonitorWorker {
}
let _ = self
.constellation_chan
.send(HangAlert::Transient(component_id.clone(), last_annotation));
.send(HangMonitorAlert::Hang(HangAlert::Transient(
component_id.clone(),
last_annotation,
)));
monitored.sent_transient_alert = true;
}
}
}
fn sample(&mut self) {
for (component_id, monitored) in self.monitored_components.iter_mut() {
let instant = Instant::now();
if let Ok(stack) = monitored.sampler.suspend_and_sample_thread() {
// TODO: support a bounded buffer that discards older samples.
self.samples
.push(Sample(component_id.clone(), instant, stack));
}
}
}
}

View file

@ -7,6 +7,8 @@
#[macro_use]
extern crate crossbeam_channel;
#[macro_use]
extern crate lazy_static;
#[macro_use]
extern crate log;
pub mod background_hang_monitor;

View file

@ -16,6 +16,7 @@ use servo_url::ServoUrl;
use std::fmt::{Debug, Error, Formatter};
#[cfg(feature = "gl")]
use std::rc::Rc;
use std::time::Duration;
use style_traits::DevicePixel;
use webrender_api::{DeviceIntPoint, DeviceIntRect, DeviceIntSize, DevicePoint, ScrollLocation};
use webvr::VRServiceManager;
@ -91,6 +92,8 @@ pub enum WindowEvent {
ToggleWebRenderDebug(WebRenderDebugOption),
/// Capture current WebRender
CaptureWebRender,
/// Toggle sampling profiler with the given sampling rate
ToggleSamplingProfiler(Duration),
}
impl Debug for WindowEvent {
@ -118,6 +121,7 @@ impl Debug for WindowEvent {
WindowEvent::SelectBrowser(..) => write!(f, "SelectBrowser"),
WindowEvent::ToggleWebRenderDebug(..) => write!(f, "ToggleWebRenderDebug"),
WindowEvent::CaptureWebRender => write!(f, "CaptureWebRender"),
WindowEvent::ToggleSamplingProfiler(..) => write!(f, "ToggleSamplingProfiler"),
}
}
}

View file

@ -124,7 +124,7 @@ use keyboard_types::webdriver::Event as WebDriverInputEvent;
use keyboard_types::KeyboardEvent;
use layout_traits::LayoutThreadFactory;
use log::{Level, LevelFilter, Log, Metadata, Record};
use msg::constellation_msg::{BackgroundHangMonitorRegister, HangAlert};
use msg::constellation_msg::{BackgroundHangMonitorRegister, HangMonitorAlert};
use msg::constellation_msg::{
BrowsingContextId, HistoryStateId, PipelineId, TopLevelBrowsingContextId,
};
@ -210,11 +210,11 @@ pub struct Constellation<Message, LTF, STF> {
/// A channel for the background hang monitor to send messages
/// to the constellation.
background_hang_monitor_sender: IpcSender<HangAlert>,
background_hang_monitor_sender: IpcSender<HangMonitorAlert>,
/// A channel for the constellation to receiver messages
/// from the background hang monitor.
background_hang_monitor_receiver: Receiver<Result<HangAlert, IpcError>>,
background_hang_monitor_receiver: Receiver<Result<HangMonitorAlert, IpcError>>,
/// An IPC channel for layout threads to send messages to the constellation.
/// This is the layout threads' view of `layout_receiver`.
@ -942,7 +942,7 @@ where
#[derive(Debug)]
enum Request {
Script((PipelineId, FromScriptMsg)),
BackgroundHangMonitor(HangAlert),
BackgroundHangMonitor(HangMonitorAlert),
Compositor(FromCompositorMsg),
Layout(FromLayoutMsg),
NetworkListener((PipelineId, FetchResponseMsg)),
@ -1008,10 +1008,17 @@ where
}
}
fn handle_request_from_background_hang_monitor(&self, message: HangAlert) {
// TODO: In case of a permanent hang being reported, add a "kill script" workflow,
// via the embedder?
warn!("Component hang alert: {:?}", message);
fn handle_request_from_background_hang_monitor(&self, message: HangMonitorAlert) {
match message {
HangMonitorAlert::Profile(bytes) => self
.embedder_proxy
.send((None, EmbedderMsg::ReportProfile(bytes))),
HangMonitorAlert::Hang(hang) => {
// TODO: In case of a permanent hang being reported, add a "kill script" workflow,
// via the embedder?
warn!("Component hang alert: {:?}", hang);
},
}
}
fn handle_request_from_network_listener(&mut self, message: (PipelineId, FetchResponseMsg)) {

View file

@ -18,7 +18,7 @@ use ipc_channel::Error;
use layout_traits::LayoutThreadFactory;
use metrics::PaintTimeMetrics;
use msg::constellation_msg::TopLevelBrowsingContextId;
use msg::constellation_msg::{BackgroundHangMonitorRegister, HangAlert};
use msg::constellation_msg::{BackgroundHangMonitorRegister, HangMonitorAlert};
use msg::constellation_msg::{BrowsingContextId, HistoryStateId, PipelineId, PipelineNamespaceId};
use net::image_cache::ImageCacheImpl;
use net_traits::image_cache::ImageCache;
@ -122,7 +122,7 @@ pub struct InitialPipelineState {
pub background_monitor_register: Option<Box<BackgroundHangMonitorRegister>>,
/// A channel for the background hang monitor to send messages to the constellation.
pub background_hang_monitor_to_constellation_chan: IpcSender<HangAlert>,
pub background_hang_monitor_to_constellation_chan: IpcSender<HangMonitorAlert>,
/// A channel for the layout thread to send messages to the constellation.
pub layout_to_constellation_chan: IpcSender<LayoutMsg>,
@ -467,7 +467,7 @@ pub struct UnprivilegedPipelineContent {
parent_pipeline_id: Option<PipelineId>,
opener: Option<BrowsingContextId>,
script_to_constellation_chan: ScriptToConstellationChan,
background_hang_monitor_to_constellation_chan: IpcSender<HangAlert>,
background_hang_monitor_to_constellation_chan: IpcSender<HangMonitorAlert>,
layout_to_constellation_chan: IpcSender<LayoutMsg>,
scheduler_chan: IpcSender<TimerSchedulerMsg>,
devtools_chan: Option<IpcSender<ScriptToDevtoolsControlMsg>>,
@ -669,7 +669,7 @@ impl UnprivilegedPipelineContent {
}
}
pub fn background_hang_monitor_to_constellation_chan(&self) -> &IpcSender<HangAlert> {
pub fn background_hang_monitor_to_constellation_chan(&self) -> &IpcSender<HangMonitorAlert> {
&self.background_hang_monitor_to_constellation_chan
}

View file

@ -160,6 +160,8 @@ pub enum EmbedderMsg {
HideIME,
/// Servo has shut down
Shutdown,
/// Report a complete sampled profile
ReportProfile(Vec<u8>),
}
impl Debug for EmbedderMsg {
@ -189,6 +191,7 @@ impl Debug for EmbedderMsg {
EmbedderMsg::Shutdown => write!(f, "Shutdown"),
EmbedderMsg::AllowOpeningBrowser(..) => write!(f, "AllowOpeningBrowser"),
EmbedderMsg::BrowserCreated(..) => write!(f, "BrowserCreated"),
EmbedderMsg::ReportProfile(..) => write!(f, "ReportProfile"),
}
}
}

View file

@ -350,6 +350,24 @@ pub enum HangAnnotation {
Script(ScriptHangAnnotation),
}
/// Hang-alerts are sent by the monitor to the constellation.
#[derive(Deserialize, Serialize)]
pub enum HangMonitorAlert {
/// A component hang has been detected.
Hang(HangAlert),
/// Report a completed sampled profile.
Profile(Vec<u8>),
}
impl fmt::Debug for HangMonitorAlert {
fn fmt(&self, fmt: &mut fmt::Formatter) -> fmt::Result {
match *self {
HangMonitorAlert::Hang(..) => write!(fmt, "Hang"),
HangMonitorAlert::Profile(..) => write!(fmt, "Profile"),
}
}
}
/// Hang-alerts are sent by the monitor to the constellation.
#[derive(Deserialize, Serialize)]
pub enum HangAlert {

View file

@ -406,6 +406,10 @@ where
}
},
WindowEvent::ToggleSamplingProfiler(rate) => {
HangMonitorRegister::toggle(rate);
},
WindowEvent::ToggleWebRenderDebug(option) => {
self.compositor.toggle_webrender_debug(option);
},

153
etc/profilicate.py Normal file
View file

@ -0,0 +1,153 @@
#!/usr/bin/env python
# Copyright 2018 The Servo Project Developers. See the COPYRIGHT
# file at the top-level directory of this distribution.
#
# Licensed under the Apache License, Version 2.0 <LICENSE-APACHE or
# http://www.apache.org/licenses/LICENSE-2.0> or the MIT license
# <LICENSE-MIT or http://opensource.org/licenses/MIT>, at your
# option. This file may not be copied, modified, or distributed
# except according to those terms.
# Script to take raw sample output from Servo sampling profiler and
# output a [processed profile]. Based largely on [this script] and
# [this documentation].
#
# [processed profile]: https://github.com/firefox-devtools/profiler/blob/master/docs-developer/processed-profile-format.md
# [this script]: https://github.com/firefox-devtools/profiler/blob/master/src/profile-logic/import/linux-perf.js
# [this documentation]: https://github.com/firefox-devtools/profiler/blob/master/src/types/profile.js
from collections import defaultdict
import json
import sys
class StringTable:
def __init__(self):
self.table = {}
self.idx = 0
def get(self, s):
assert s
if s not in self.table:
self.table[s] = self.idx
self.idx += 1
return self.table[s]
def length(self):
return len(self.table.keys())
def contents(self):
return sorted(self.table.keys(), key=self.table.__getitem__)
with open(sys.argv[1]) as f:
profile = json.load(f)
rate = profile["rate"]
samples = profile["data"]
startTime = profile["start"]
frames = {}
stacks = {}
thread_data = defaultdict(list)
thread_order = {}
for sample in samples:
if sample['name']:
name = sample['name']
else:
name = "%s %d %d" % (sample['type'], sample['namespace'], sample['index'])
thread_data[name].append((sample['time'], sample['frames']))
if name not in thread_order:
thread_order[name] = (sample['namespace'], sample['index'])
tid = 0
threads = []
for (name, raw_samples) in sorted(thread_data.iteritems(), key=lambda x: thread_order[x[0]]):
string_table = StringTable()
tid += 1
stackMap = {}
stacks = []
frameMap = {}
frames = []
samples = []
for sample in raw_samples:
prefix = None
for frame in sample[1]:
if not frame['name']:
continue
if not frame['name'] in frameMap:
frameMap[frame['name']] = len(frames)
frame_index = string_table.get(frame['name'])
frames.append([frame_index])
frame = frameMap[frame['name']]
stack_key = "%d,%d" % (frame, prefix) if prefix else str(frame)
if stack_key not in stackMap:
stackMap[stack_key] = len(stacks)
stacks.append([frame, prefix])
stack = stackMap[stack_key]
prefix = stack
samples.append([stack, sample[0]])
threads.append({
'tid': tid,
'name': name,
'markers': {
'schema': {
'name': 0,
'time': 1,
'data': 2,
},
'data': [],
},
'samples': {
'schema': {
'stack': 0,
'time': 1,
'responsiveness': 2,
'rss': 2,
'uss': 4,
'frameNumber': 5,
},
'data': samples,
},
'frameTable': {
'schema': {
'location': 0,
'implementation': 1,
'optimizations': 2,
'line': 3,
'category': 4,
},
'data': frames,
},
'stackTable': {
'schema': {
'frame': 0,
'prefix': 1,
},
'data': stacks,
},
'stringTable': string_table.contents(),
})
output = {
'meta': {
'interval': rate,
'processType': 0,
'product': 'Servo',
'stackwalk': 1,
'startTime': startTime,
'version': 4,
'presymbolicated': True,
},
'libs': [],
'threads': threads,
}
print(json.dumps(output))

View file

@ -519,7 +519,8 @@ impl ServoGlue {
EmbedderMsg::SetFullscreenState(..) |
EmbedderMsg::ShowIME(..) |
EmbedderMsg::HideIME |
EmbedderMsg::Panic(..) => {},
EmbedderMsg::Panic(..) |
EmbedderMsg::ReportProfile(..) => {},
}
}
Ok(())

View file

@ -16,9 +16,13 @@ use servo::servo_config::opts;
use servo::servo_config::prefs::PREFS;
use servo::servo_url::ServoUrl;
use servo::webrender_api::ScrollLocation;
use std::env;
use std::fs::File;
use std::io::Write;
use std::mem;
use std::rc::Rc;
use std::thread;
use std::time::Duration;
use tinyfiledialogs::{self, MessageBoxIcon};
pub struct Browser {
@ -112,6 +116,14 @@ impl Browser {
.shortcut(CMD_OR_CONTROL, 'Q', || {
self.event_queue.push(WindowEvent::Quit);
})
.shortcut(CMD_OR_CONTROL, 'P', || {
let rate = env::var("SAMPLING_RATE")
.ok()
.and_then(|s| s.parse().ok())
.unwrap_or(10);
self.event_queue.push(WindowEvent::ToggleSamplingProfiler(
Duration::from_millis(rate)));
})
.shortcut(Modifiers::CONTROL, Key::F9, || {
self.event_queue.push(WindowEvent::CaptureWebRender)
})
@ -378,6 +390,15 @@ impl Browser {
EmbedderMsg::HideIME => {
debug!("HideIME received");
},
EmbedderMsg::ReportProfile(bytes) => {
let filename = env::var("PROFILE_OUTPUT")
.unwrap_or("samples.json".to_string());
let result = File::create(&filename)
.and_then(|mut f| f.write_all(&bytes));
if let Err(e) = result {
error!("Failed to store profile: {}", e);
}
}
}
}
}