Profiling in lieu of time::time, rm util alias

src/components/servo-gfx/font_context.rs

@@ -7,6 +7,8 @@ use font::{SpecifiedFontStyle, UsedFontStyle};
 use font_list::FontList;
 use servo_util::cache::Cache;
 use servo_util::cache::MonoCache;
+use servo_util::time::ProfilerChan;
+
 use platform::font::FontHandle;
 use platform::font_context::FontContextHandle;
 
@@ -42,9 +44,14 @@ pub struct FontContext {
 
 #[allow(non_implicitly_copyable_typarams)]
 pub impl<'self> FontContext {
-    fn new(backend: BackendType, needs_font_list: bool) -> FontContext {
+    fn new(backend: BackendType,
+           needs_font_list: bool,
+           prof_chan: ProfilerChan)
+           -> FontContext {
         let handle = FontContextHandle::new();
-        let font_list = if needs_font_list { Some(FontList::new(&handle)) } else { None };
+        let font_list = if needs_font_list { 
+                            Some(FontList::new(&handle, prof_chan.clone())) }
+                        else { None };
 
         // TODO: Allow users to specify these.
         let mut generic_fonts = HashMap::with_capacity(5);

src/components/servo-gfx/font_list.rs

@@ -7,7 +7,10 @@ use gfx_font::FontHandleMethods;
 use platform::font::FontHandle;
 use platform::font_context::FontContextHandle;
 use platform::font_list::FontListHandle;
+use servo_util::time;
 use servo_util::time::time;
+use servo_util::time::profile;
+use servo_util::time::ProfilerChan;
 
 use core::hashmap::HashMap;
 
@@ -22,14 +25,18 @@ trait FontListHandleMethods {
 pub struct FontList {
     family_map: FontFamilyMap,
     handle: FontListHandle,
+    prof_chan: ProfilerChan,
 }
 
 pub impl FontList {
-    fn new(fctx: &FontContextHandle) -> FontList {
+    fn new(fctx: &FontContextHandle,
+           prof_chan: ProfilerChan)
+           -> FontList {
         let handle = FontListHandle::new(fctx);
         let mut list = FontList {
             handle: handle,
             family_map: HashMap::new(),
+            prof_chan: prof_chan.clone(),
         };
         list.refresh(fctx);
         list
@@ -40,7 +47,7 @@ pub impl FontList {
         // changed.  Does OSX have a notification for this event?
         //
         // Should font families with entries be invalidated/refreshed too?
-        do time("gfx::font_list: regenerating available font families and faces") {
+        do profile(time::GfxRegenFontFF, self.prof_chan.clone()) {
             self.family_map = self.handle.get_available_families();
         }
     }

src/components/servo-gfx/render_layers.rs

@@ -6,6 +6,7 @@ use compositor::{LayerBuffer, LayerBufferSet};
 use display_list::DisplayList;
 use opts::Opts;
 use servo_util::time;
+use servo_util::time::ProfilerChan;
 
 use azure::azure_hl::{B8G8R8A8, DrawTarget};
 use core::comm::Chan;
@@ -28,14 +29,16 @@ type RenderFn<'self> = &'self fn(layer: *RenderLayer,
 /// might be the old layer buffer if it had the appropriate size and format).
 pub fn render_layers(layer_ref: *RenderLayer,
                      opts: &Opts,
-                     f: RenderFn) -> LayerBufferSet {
+                     prof_chan: ProfilerChan,
+                     f: RenderFn)
+                     -> LayerBufferSet {
     let tile_size = opts.tile_size;
 
     // FIXME: Try not to create a new array here.
     let mut new_buffer_ports = ~[];
 
     // Divide up the layer into tiles.
-    do time::time("rendering: preparing buffers") {
+    do time::profile(time::RenderingPrepBuff, prof_chan.clone()) {
         let layer: &RenderLayer = unsafe { cast::transmute(layer_ref) };
         let mut y = 0;
         while y < layer.size.height {
@@ -125,7 +128,7 @@ pub fn render_layers(layer_ref: *RenderLayer,
     }
 
     let mut new_buffers = ~[];
-    do time::time("rendering: waiting on subtasks") {
+    do time::profile(time::RenderingWaitSubtasks, prof_chan.clone()) {
         for new_buffer_ports.each |new_buffer_port| {
             new_buffers.push(new_buffer_port.recv());
         }

src/components/servo-gfx/render_task.rs

@@ -17,7 +17,11 @@ use core::comm::{Port, SharedChan};
 use core::task::SingleThreaded;
 use std::task_pool::TaskPool;
 use servo_net::util::spawn_listener;
+
+use servo_util::time;
 use servo_util::time::time;
+use servo_util::time::profile;
+use servo_util::time::ProfilerChan;
 
 pub enum Msg {
     RenderMsg(RenderLayer),
@@ -26,7 +30,9 @@ pub enum Msg {
 
 pub type RenderTask = SharedChan<Msg>;
 
-pub fn RenderTask<C:Compositor + Owned>(compositor: C, opts: Opts) -> RenderTask {
+pub fn RenderTask<C:Compositor + Owned>(compositor: C,
+                                        opts: Opts,
+                                        prof_chan: ProfilerChan) -> RenderTask {
     let compositor_cell = Cell(compositor);
     let opts_cell = Cell(opts);
     let render_task = do spawn_listener |po: Port<Msg>| {
@@ -39,13 +45,17 @@ pub fn RenderTask<C:Compositor + Owned>(compositor: C, opts: Opts) -> RenderTask
         let opts = opts_cell.with_ref(|o| copy *o);
         let n_threads = opts.n_render_threads;
         let new_opts_cell = Cell(opts);
+        let prof_chan2 = prof_chan.clone();
 
         let thread_pool = do TaskPool::new(n_threads, Some(SingleThreaded)) {
             let opts_cell = Cell(new_opts_cell.with_ref(|o| copy *o));
+            let prof_chan = prof_chan2.clone();
             let f: ~fn(uint) -> ThreadRenderContext = |thread_index| {
                 ThreadRenderContext {
                     thread_index: thread_index,
-                    font_ctx: @mut FontContext::new(opts_cell.with_ref(|o| o.render_backend), false),
+                    font_ctx: @mut FontContext::new(opts_cell.with_ref(|o| o.render_backend),
+                                                    false,
+                                                    prof_chan.clone()),
                     opts: opts_cell.with_ref(|o| copy *o),
                 }
             };
@@ -58,7 +68,8 @@ pub fn RenderTask<C:Compositor + Owned>(compositor: C, opts: Opts) -> RenderTask
             compositor: compositor,
             layer_buffer_set_port: Cell(layer_buffer_set_port),
             thread_pool: thread_pool,
-            opts: opts_cell.take()
+            opts: opts_cell.take(),
+            prof_chan: prof_chan.clone()
         };
         r.start();
     };
@@ -78,6 +89,7 @@ priv struct Renderer<C> {
     layer_buffer_set_port: Cell<comm::Port<LayerBufferSet>>,
     thread_pool: TaskPool<ThreadRenderContext>,
     opts: Opts,
+    prof_chan: ProfilerChan,
 }
 
 impl<C: Compositor + Owned> Renderer<C> {
@@ -111,10 +123,10 @@ impl<C: Compositor + Owned> Renderer<C> {
 
         debug!("renderer: rendering");
 
-        do time(~"rendering") {
+        do profile(time::Rendering, self.prof_chan.clone()) {
             let layer_buffer_set_channel = layer_buffer_set_channel_cell.take();
 
-            let layer_buffer_set = do render_layers(&render_layer, &self.opts)
+            let layer_buffer_set = do render_layers(&render_layer, &self.opts, self.prof_chan.clone())
                     |render_layer_ref, layer_buffer, buffer_chan| {
                 let layer_buffer_cell = Cell(layer_buffer);
                 do self.thread_pool.execute |thread_render_context| {

src/components/servo-util/time.rs

@@ -4,6 +4,120 @@
 
 // Timing functions.
 use std::time::precise_time_ns;
+use core::cell::Cell;
+use core::comm::{Port, SharedChan};
+use core::os::getenv;
+
+pub enum ProfilerMsg {
+    Compositing,
+    LayoutPerform,
+    LayoutQuery,
+    LayoutAuxInit,
+    LayoutSelectorMatch,
+    LayoutTreeBuilder,
+    LayoutMain,
+    LayoutDispListBuild,
+    GfxRegenFontFF,
+    RenderingPrepBuff,
+    RenderingWaitSubtasks,
+    Rendering,
+}
+
+pub type ProfilerChan = SharedChan<(ProfilerMsg, uint)>;
+pub type ProfilerPort = Port<(ProfilerMsg, uint)>;
+pub struct ProfilerTask {
+    chan: ProfilerChan,
+}
+
+impl ProfilerTask {
+    pub fn new(prof_port: ProfilerPort,
+               prof_chan: ProfilerChan)
+               -> ProfilerTask {
+        let prof_port = Cell(prof_port);
+
+        do spawn {
+            let mut profiler_context = ProfilerContext::new(prof_port.take());
+            profiler_context.start();
+        }
+
+        ProfilerTask {
+            chan: prof_chan
+        }
+    }
+}
+
+pub struct ProfilerContext {
+    port: ProfilerPort,
+    buckets: [~[uint], ..12],
+    mut last_print: u64,
+}
+
+impl ProfilerContext {
+    pub fn new(port: ProfilerPort) -> ProfilerContext {
+        ProfilerContext {
+            port: port,
+            buckets: [~[], ..12],
+            last_print: 0,
+        }
+    }
+
+    pub fn start(&mut self) {
+        loop {
+            let msg = self.port.recv();
+            self.handle_msg(msg);
+        }
+    }
+
+    priv fn handle_msg(&mut self, msg: (ProfilerMsg, uint)) {
+        let (prof_msg, t) = msg;
+        self.buckets[prof_msg as uint].push(t);
+        let verbose = getenv("SERVO_PROFILER");
+        match verbose {
+            Some(~"1") => {
+                let cur_time = precise_time_ns() / 1000000000u64;
+                if cur_time - self.last_print > 5 {
+                    self.last_print = cur_time;
+                    let mut i = 0;
+                    for self.buckets.each |bucket| {
+                        let prof_msg = match i {
+                            0 => Compositing,
+                            1 => LayoutPerform,
+                            2 => LayoutQuery,
+                            3 => LayoutAuxInit,
+                            4 => LayoutSelectorMatch,
+                            5 => LayoutTreeBuilder,
+                            6 => LayoutMain,
+                            7 => LayoutDispListBuild,
+                            8 => GfxRegenFontFF,
+                            9 => RenderingPrepBuff,
+                            10 => RenderingWaitSubtasks,
+                            11 => Rendering,
+                            _ => fail!()
+                        };
+                        io::println(fmt!("%?: %f", prof_msg,
+                                     (bucket.foldl(0 as uint, |a, b| a + *b) as float) / 
+                                     (bucket.len() as float)));
+                        i += 1;
+                    }
+                }
+            }
+            _ => ()
+        }
+
+    }
+}
+
+pub fn profile<T>(msg: ProfilerMsg, 
+                  prof_chan: ProfilerChan,
+                  callback: &fn() -> T)
+                  -> T {
+    let start_time = precise_time_ns();
+    let val = callback();
+    let end_time = precise_time_ns();
+    let ms = ((end_time - start_time) / 1000000u64) as uint;
+    prof_chan.send((msg, ms));
+    return val;
+}
 
 pub fn time<T>(msg: &str, callback: &fn() -> T) -> T{
     let start_time = precise_time_ns();

src/components/servo/compositing/mod.rs

@@ -22,6 +22,8 @@ use layers::layers::{Image, ImageData, ImageLayer, ImageLayerKind, RGB24Format,
 use layers::rendergl;
 use layers::scene::Scene;
 use servo_util::{time, url};
+use servo_util::time::profile;
+use servo_util::time::ProfilerChan;
 
 mod resize_rate_limiter;
 
@@ -33,11 +35,14 @@ pub struct CompositorImpl {
 
 impl CompositorImpl {
     /// Creates a new compositor instance.
-    pub fn new(script_chan: SharedChan<ScriptMsg>, opts: Opts) -> CompositorImpl {
+    pub fn new(script_chan: SharedChan<ScriptMsg>,
+               opts: Opts,
+               prof_chan: ProfilerChan)
+               -> CompositorImpl {
         let script_chan = Cell(script_chan);
         let chan: Chan<Msg> = do on_osmain |port| {
             debug!("preparing to enter main loop");
-            run_main_loop(port, script_chan.take(), &opts);
+            run_main_loop(port, script_chan.take(), &opts, prof_chan.clone());
         };
 
         CompositorImpl {
@@ -79,7 +84,7 @@ impl ImageData for AzureDrawTargetImageData {
     }
 }
 
-fn run_main_loop(po: Port<Msg>, script_chan: SharedChan<ScriptMsg>, opts: &Opts) {
+fn run_main_loop(po: Port<Msg>, script_chan: SharedChan<ScriptMsg>, opts: &Opts, prof_chan:ProfilerChan) {
     let app: Application = ApplicationMethods::new();
     let window: @mut Window = WindowMethods::new(&app);
     let resize_rate_limiter = @mut ResizeRateLimiter(script_chan.clone());
@@ -185,7 +190,7 @@ fn run_main_loop(po: Port<Msg>, script_chan: SharedChan<ScriptMsg>, opts: &Opts)
     };
 
     do window.set_composite_callback {
-        do time::time(~"compositing") {
+        do profile(time::Compositing, prof_chan.clone()) {
             debug!("compositor: compositing");
             // Adjust the layer dimensions as necessary to correspond to the size of the window.
             scene.size = window.size();