mildly cleaner profiling code in util::time

This commit is contained in:
Tim Kuehn 2013-07-03 20:27:36 -07:00
parent 66c9828a9e
commit 9f6cbf91c6
4 changed files with 53 additions and 53 deletions

View file

@ -8,7 +8,7 @@
use azure::azure_hl::{BackendType, CairoBackend, CoreGraphicsBackend}; use azure::azure_hl::{BackendType, CairoBackend, CoreGraphicsBackend};
use azure::azure_hl::{CoreGraphicsAcceleratedBackend, Direct2DBackend, SkiaBackend}; use azure::azure_hl::{CoreGraphicsAcceleratedBackend, Direct2DBackend, SkiaBackend};
use std::f64; use std::float;
use std::result; use std::result;
use std::uint; use std::uint;
@ -17,7 +17,7 @@ pub struct Opts {
render_backend: BackendType, render_backend: BackendType,
n_render_threads: uint, n_render_threads: uint,
tile_size: uint, tile_size: uint,
profiler_period: Option<f64>, profiler_period: Option<float>,
/// A scale factor to apply to tiles, to allow rendering tiles at higher resolutions for /// A scale factor to apply to tiles, to allow rendering tiles at higher resolutions for
/// testing pan and zoom code. /// testing pan and zoom code.
@ -40,9 +40,10 @@ pub fn from_cmdline_args(args: &[~str]) -> Opts {
]; ];
let opt_match = match getopts::getopts(args, opts) { let opt_match = match getopts::getopts(args, opts) {
result::Ok(m) => { copy m } result::Ok(m) => m,
result::Err(f) => { fail!(getopts::fail_str(copy f)) } result::Err(f) => fail!(getopts::fail_str(copy f)),
}; };
let urls = if opt_match.free.is_empty() { let urls = if opt_match.free.is_empty() {
fail!(~"servo asks that you provide 1 or more URLs") fail!(~"servo asks that you provide 1 or more URLs")
} else { } else {
@ -82,10 +83,10 @@ pub fn from_cmdline_args(args: &[~str]) -> Opts {
None => 1, // FIXME: Number of cores. None => 1, // FIXME: Number of cores.
}; };
let profiler_period: Option<f64> = let profiler_period: Option<float> =
// if only flag is present, default to 5 second period // if only flag is present, default to 5 second period
match getopts::opt_default(&opt_match, "p", "5") { match getopts::opt_default(&opt_match, "p", "5") {
Some(period) => Some(f64::from_str(period).get()), Some(period) => Some(float::from_str(period).get()),
None => None, None => None,
}; };

View file

@ -128,8 +128,8 @@ impl<C: RenderListener + Send> RenderTask<C> {
PaintPermissionGranted => { PaintPermissionGranted => {
self.paint_permission = true; self.paint_permission = true;
match self.last_paint_msg { match self.last_paint_msg {
Some((ref layer_buffer_set, ref layer_size)) => { Some((ref layer_buffer_set, layer_size)) => {
self.compositor.paint(self.id, layer_buffer_set.clone(), *layer_size); self.compositor.paint(self.id, layer_buffer_set.clone(), layer_size);
self.compositor.set_render_state(IdleRenderState); self.compositor.set_render_state(IdleRenderState);
} }
None => {} None => {}

View file

@ -109,7 +109,7 @@ fn run(opts: &Opts) {
do spawn { do spawn {
loop { loop {
extra::timer::sleep(&uv_global_loop::get(), extra::timer::sleep(&uv_global_loop::get(),
(period * 1000f64) as uint); (period * 1000f) as uint);
profiler_chan.send(PrintMsg); profiler_chan.send(PrintMsg);
} }
} }

View file

@ -45,10 +45,11 @@ pub enum ProfilerCategory {
} }
// FIXME(#5873) this should be initialized by a NUM_BUCKETS cast, // FIXME(#5873) this should be initialized by a NUM_BUCKETS cast,
static BUCKETS: uint = 13; static BUCKETS: uint = 13;
type ProfilerBuckets = [(ProfilerCategory, ~[float]), ..BUCKETS];
pub enum ProfilerMsg { pub enum ProfilerMsg {
// Normal message used for reporting time // Normal message used for reporting time
TimeMsg(ProfilerCategory, f64), TimeMsg(ProfilerCategory, float),
// Message used to force print the profiling metrics // Message used to force print the profiling metrics
PrintMsg, PrintMsg,
} }
@ -56,7 +57,7 @@ pub enum ProfilerMsg {
// back end of the profiler that handles data aggregation and performance metrics // back end of the profiler that handles data aggregation and performance metrics
pub struct Profiler { pub struct Profiler {
port: Port<ProfilerMsg>, port: Port<ProfilerMsg>,
buckets: ~[(ProfilerCategory, ~[f64])], buckets: ProfilerBuckets,
last_msg: Option<ProfilerMsg>, last_msg: Option<ProfilerMsg>,
} }
@ -67,29 +68,30 @@ impl ProfilerCategory {
} }
// enumeration of all ProfilerCategory types // enumeration of all ProfilerCategory types
// FIXME(tkuehn): this is ugly and error-prone, // TODO(tkuehn): is there a better way to ensure proper order of categories?
// but currently we lack better alternatives without an enum enumeration priv fn empty_buckets() -> ProfilerBuckets {
priv fn empty_buckets() -> ~[(ProfilerCategory, ~[f64])] { let buckets = [
let mut vec = ~[]; (CompositingCategory, ~[]),
vec.push((CompositingCategory, ~[])); (LayoutQueryCategory, ~[]),
vec.push((LayoutQueryCategory, ~[])); (LayoutPerformCategory, ~[]),
vec.push((LayoutPerformCategory, ~[])); (LayoutAuxInitCategory, ~[]),
vec.push((LayoutAuxInitCategory, ~[])); (LayoutSelectorMatchCategory, ~[]),
vec.push((LayoutSelectorMatchCategory, ~[])); (LayoutTreeBuilderCategory, ~[]),
vec.push((LayoutTreeBuilderCategory, ~[])); (LayoutMainCategory, ~[]),
vec.push((LayoutMainCategory, ~[])); (LayoutShapingCategory, ~[]),
vec.push((LayoutShapingCategory, ~[])); (LayoutDispListBuildCategory, ~[]),
vec.push((LayoutDispListBuildCategory, ~[])); (GfxRegenAvailableFontsCategory, ~[]),
vec.push((GfxRegenAvailableFontsCategory, ~[])); (RenderingDrawingCategory, ~[]),
vec.push((RenderingDrawingCategory, ~[])); (RenderingPrepBuffCategory, ~[]),
vec.push((RenderingPrepBuffCategory, ~[])); (RenderingCategory, ~[]),
vec.push((RenderingCategory, ~[])); ];
ProfilerCategory::check_order(vec); ProfilerCategory::check_order(&buckets);
vec buckets
} }
priv fn check_order(vec: &[(ProfilerCategory, ~[f64])]) { // ensure that the order of the buckets matches the order of the enum categories
priv fn check_order(vec: &ProfilerBuckets) {
for vec.iter().advance |&(category, _)| { for vec.iter().advance |&(category, _)| {
if category != vec[category as uint].first() { if category != vec[category as uint].first() {
fail!("Enum category does not match bucket index. This is a bug."); fail!("Enum category does not match bucket index. This is a bug.");
@ -136,13 +138,11 @@ impl Profiler {
priv fn handle_msg(&mut self, msg: ProfilerMsg) { priv fn handle_msg(&mut self, msg: ProfilerMsg) {
match msg { match msg {
TimeMsg(category, t) => match self.buckets[category as uint] { TimeMsg(category, t) => match self.buckets[category as uint] {
// FIXME(#3874): this should be a let (cat, ref mut bucket) = ..., //TODO(tkuehn): would be nice to have tuple.second_mut()
// not a match (_, ref mut data) => data.push(t),
(_, ref mut data) => {
data.push(t);
}
}, },
PrintMsg => match self.last_msg { PrintMsg => match self.last_msg {
// only print if more data has arrived since the last printout
Some(TimeMsg(*)) => self.print_buckets(), Some(TimeMsg(*)) => self.print_buckets(),
_ => {} _ => {}
}, },
@ -155,20 +155,19 @@ impl Profiler {
"_category_", "_mean (ms)_", "_median (ms)_", "_category_", "_mean (ms)_", "_median (ms)_",
"_min (ms)_", "_max (ms)_", "_bucket size_")); "_min (ms)_", "_max (ms)_", "_bucket size_"));
for self.buckets.mut_iter().advance |bucket| { for self.buckets.mut_iter().advance |bucket| {
match *bucket { let (category, data) = match *bucket {
(category, ref mut data) => { (category, ref mut data) => (category, data),
tim_sort(*data); };
let data_len = data.len(); tim_sort(*data);
if data_len > 0 { let data_len = data.len();
let (mean, median, min, max) = if data_len > 0 {
(data.iter().fold(0f64, |a, b| a + *b) / (data_len as f64), let (mean, median, &min, &max) =
data[data_len / 2], (data.iter().fold(0f, |a, b| a + *b) / (data_len as float),
data.iter().min(), data[data_len / 2],
data.iter().max()); data.iter().min().unwrap(),
println(fmt!("%-30s: %15.4? %15.4? %15.4? %15.4? %15u", data.iter().max().unwrap());
category.format(), mean, median, min, max, data_len)); println(fmt!("%-30s: %15.4f %15.4f %15.4f %15.4f %15u",
} category.format(), mean, median, min, max, data_len));
}
} }
} }
println(""); println("");
@ -183,7 +182,7 @@ pub fn profile<T>(category: ProfilerCategory,
let start_time = precise_time_ns(); let start_time = precise_time_ns();
let val = callback(); let val = callback();
let end_time = precise_time_ns(); let end_time = precise_time_ns();
let ms = ((end_time - start_time) as f64 / 1000000f64); let ms = ((end_time - start_time) as float / 1000000f);
profiler_chan.send(TimeMsg(category, ms)); profiler_chan.send(TimeMsg(category, ms));
return val; return val;
} }
@ -192,8 +191,8 @@ pub fn time<T>(msg: &str, callback: &fn() -> T) -> T{
let start_time = precise_time_ns(); let start_time = precise_time_ns();
let val = callback(); let val = callback();
let end_time = precise_time_ns(); let end_time = precise_time_ns();
let ms = ((end_time - start_time) as f64 / 1000000f64); let ms = ((end_time - start_time) as float / 1000000f);
if ms >= 5f64 { if ms >= 5f {
debug!("%s took %? ms", msg, ms); debug!("%s took %? ms", msg, ms);
} }
return val; return val;