auto merge of #478 : tkuehn/servo/profiling, r=pcwalton

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::GfxRegenAvailableFontsCategory, 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::RenderingPrepBuffCategory, 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::RenderingWaitSubtasksCategory, 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::RenderingCategory, 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,122 @@
 
 // Timing functions.
 use std::time::precise_time_ns;
+use core::cell::Cell;
+use core::comm::{Port, SharedChan};
+use core::os::getenv;
+
+pub enum ProfilerCategory {
+    CompositingCategory,
+    LayoutPerformCategory,
+    LayoutQueryCategory,
+    LayoutAuxInitCategory,
+    LayoutSelectorMatchCategory,
+    LayoutTreeBuilderCategory,
+    LayoutMainCategory,
+    LayoutDispListBuildCategory,
+    GfxRegenAvailableFontsCategory,
+    RenderingPrepBuffCategory,
+    RenderingWaitSubtasksCategory,
+    RenderingCategory,
+}
+// change this whenever buckets are added/rm'd
+static NUM_BUCKETS: uint = 12;
+
+pub type ProfilerChan = SharedChan<(ProfilerCategory, uint)>;
+pub type ProfilerPort = Port<(ProfilerCategory, 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], ..NUM_BUCKETS],
+    verbose: Option<~str>,
+    mut last_print: u64,
+}
+
+impl ProfilerContext {
+    pub fn new(port: ProfilerPort) -> ProfilerContext {
+        ProfilerContext {
+            port: port,
+            buckets: [~[], ..NUM_BUCKETS],
+            verbose: getenv("SERVO_PROFILER"),
+            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: (ProfilerCategory, uint)) {
+        let (prof_msg, t) = msg;
+        self.buckets[prof_msg as uint].push(t);
+        if self.verbose.is_some() {
+            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 {
+                        // must be in same order as ProfilerCategory
+                        0 => CompositingCategory,
+                        1 => LayoutPerformCategory,
+                        2 => LayoutQueryCategory,
+                        3 => LayoutAuxInitCategory,
+                        4 => LayoutSelectorMatchCategory,
+                        5 => LayoutTreeBuilderCategory,
+                        6 => LayoutMainCategory,
+                        7 => LayoutDispListBuildCategory,
+                        8 => GfxRegenAvailableFontsCategory,
+                        9 => RenderingPrepBuffCategory,
+                        10 => RenderingWaitSubtasksCategory,
+                        11 => RenderingCategory,
+                        _ => fail!()
+                    };
+                    io::println(fmt!("%?: %f", prof_msg,
+                                 (bucket.foldl(0 as uint, |a, b| a + *b) as float) / 
+                                 (bucket.len() as float)));
+                    i += 1;
+                }
+                io::println("");
+            }
+        }
+
+    }
+}
+
+pub fn profile<T>(cat: ProfilerCategory, 
+                  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((cat, 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::CompositingCategory, prof_chan.clone()) {
             debug!("compositor: compositing");
             // Adjust the layer dimensions as necessary to correspond to the size of the window.
             scene.size = window.size();

src/components/servo/engine.rs

@@ -19,6 +19,10 @@ use servo_net::resource_task::ResourceTask;
 use servo_net::resource_task;
 use std::net::url::Url;
 
+use servo_util::time;
+use servo_util::time::ProfilerChan;
+use servo_util::time::ProfilerPort;
+
 pub type EngineTask = Chan<Msg>;
 
 pub enum Msg {
@@ -34,6 +38,7 @@ pub struct Engine {
     image_cache_task: ImageCacheTask,
     layout_task: LayoutTask,
     script_task: ScriptTask,
+    profiler_task: time::ProfilerTask,
 }
 
 impl Engine {
@@ -42,16 +47,25 @@ impl Engine {
                  script_port: Port<ScriptMsg>,
                  script_chan: SharedChan<ScriptMsg>,
                  resource_task: ResourceTask,
-                 image_cache_task: ImageCacheTask)
+                 image_cache_task: ImageCacheTask,
+                 prof_port: ProfilerPort,
+                 prof_chan: ProfilerChan)
                  -> EngineTask {
         let (script_port, script_chan) = (Cell(script_port), Cell(script_chan));
+        let prof_port = Cell(prof_port);
         let opts = Cell(copy *opts);
 
         do spawn_listener::<Msg> |request| {
-            let render_task = RenderTask(compositor.clone(), opts.with_ref(|o| copy *o));
+            let profiler_task = time::ProfilerTask::new(prof_port.take(), prof_chan.clone());
+            let render_task = RenderTask(compositor.clone(),
+                                         opts.with_ref(|o| copy *o),
+                                         prof_chan.clone());
 
             let opts = opts.take();
-            let layout_task = LayoutTask(render_task.clone(), image_cache_task.clone(), opts);
+            let layout_task = LayoutTask(render_task.clone(),
+                                         image_cache_task.clone(),
+                                         opts,
+                                         profiler_task.chan.clone());
 
             let script_task = ScriptTask::new(script_port.take(),
                                               script_chan.take(),
@@ -59,6 +73,7 @@ impl Engine {
                                               resource_task.clone(),
                                               image_cache_task.clone());
 
+
             Engine {
                 request_port: request,
                 compositor: compositor.clone(),
@@ -67,6 +82,7 @@ impl Engine {
                 image_cache_task: image_cache_task.clone(),
                 layout_task: layout_task,
                 script_task: script_task,
+                profiler_task: profiler_task,
             }.run()
         }
     }

src/components/servo/layout/layout_task.rs

@@ -17,7 +17,10 @@ use layout::display_list_builder::{DisplayListBuilder, FlowDisplayListBuilderMet
 use layout::flow::FlowContext;
 use scripting::script_task::{ScriptMsg, SendEventMsg};
 use util::task::spawn_listener;
-use util::time::time;
+use servo_util::time;
+use servo_util::time::time;
+use servo_util::time::profile;
+use servo_util::time::ProfilerChan;
 
 use core::cell::Cell;
 use core::comm::{Chan, Port, SharedChan};
@@ -88,9 +91,15 @@ pub struct BuildData {
 
 pub fn LayoutTask(render_task: RenderTask,
                   img_cache_task: ImageCacheTask,
-                  opts: Opts) -> LayoutTask {
+                  opts: Opts,
+                  prof_chan: ProfilerChan)
+                  -> LayoutTask {
     SharedChan::new(do spawn_listener::<Msg> |from_script| {
-        let mut layout = Layout(render_task.clone(), img_cache_task.clone(), from_script, &opts);
+        let mut layout = Layout(render_task.clone(),
+                         img_cache_task.clone(),
+                         from_script,
+                         &opts,
+                         prof_chan.clone());
         layout.start();
     })
 }
@@ -104,14 +113,16 @@ struct Layout {
     // This is used to root reader data
     layout_refs: ~[@mut LayoutData],
     css_select_ctx: @mut SelectCtx,
+    prof_chan: ProfilerChan,
 }
 
 fn Layout(render_task: RenderTask, 
           image_cache_task: ImageCacheTask,
           from_script: Port<Msg>,
-          opts: &Opts)
+          opts: &Opts,
+          prof_chan: ProfilerChan)
        -> Layout {
-    let fctx = @mut FontContext::new(opts.render_backend, true);
+    let fctx = @mut FontContext::new(opts.render_backend, true, prof_chan.clone());
 
     Layout {
         render_task: render_task,
@@ -120,7 +131,8 @@ fn Layout(render_task: RenderTask,
         from_script: from_script,
         font_ctx: fctx,
         layout_refs: ~[],
-        css_select_ctx: @mut new_css_select_ctx()
+        css_select_ctx: @mut new_css_select_ctx(),
+        prof_chan: prof_chan.clone()
     }
 }
 
@@ -141,14 +153,14 @@ impl Layout {
             BuildMsg(data) => {
                 let data = Cell(data);
 
-                do time("layout: performing layout") {
+                do profile(time::LayoutPerformCategory, self.prof_chan.clone()) {
                     self.handle_build(data.take());
                 }
 
             }
             QueryMsg(query, chan) => {
                 let chan = Cell(chan);
-                do time("layout: querying layout") {
+                do profile(time::LayoutQueryCategory, self.prof_chan.clone()) {
                     self.handle_query(query, chan.take())
                 }
             }
@@ -195,7 +207,7 @@ impl Layout {
         // Initialize layout data for each node.
         //
         // FIXME: This is inefficient. We don't need an entire traversal to do this!
-        do time("layout: aux initialization") {
+        do profile(time::LayoutAuxInitCategory, self.prof_chan.clone()) {
             node.initialize_style_for_subtree(&mut self.layout_refs);
         }
 
@@ -203,14 +215,15 @@ impl Layout {
         match data.damage {
             NoDamage | ReflowDamage => {}
             MatchSelectorsDamage => {
-                do time("layout: selector matching") {
+                do profile(time::LayoutSelectorMatchCategory, self.prof_chan.clone()) {
                     node.restyle_subtree(self.css_select_ctx);
                 }
             }
         }
 
         // Construct the flow tree.
-        let layout_root: FlowContext = do time("layout: tree construction") {
+        let layout_root: FlowContext = do profile(time::LayoutTreeBuilderCategory,
+                                                  self.prof_chan.clone()) {
             let mut builder = LayoutTreeBuilder::new();
             let layout_root: FlowContext = match builder.construct_trees(&layout_ctx, *node) {
                 Ok(root) => root,
@@ -225,7 +238,7 @@ impl Layout {
 
         // Perform the primary layout passes over the flow tree to compute the locations of all
         // the boxes.
-        do time("layout: main layout") {
+        do profile(time::LayoutMainCategory, self.prof_chan.clone()) {
             for layout_root.traverse_postorder |flow| {
                 flow.bubble_widths(&mut layout_ctx);
             };
@@ -238,7 +251,7 @@ impl Layout {
         }
 
         // Build the display list, and send it to the renderer.
-        do time("layout: display list building") {
+        do profile(time::LayoutDispListBuildCategory, self.prof_chan.clone()) {
             let builder = DisplayListBuilder {
                 ctx: &layout_ctx,
             };

src/components/servo/servo.rc

@@ -137,8 +137,11 @@ fn run(opts: &Opts) {
     let (script_port, script_chan) = comm::stream();
     let script_chan = SharedChan::new(script_chan);
 
+    let (prof_port, prof_chan) = comm::stream();
+    let prof_chan = SharedChan::new(prof_chan);
+
     // The platform event handler thread
-    let compositor = CompositorImpl::new(script_chan.clone(), copy *opts);
+    let compositor = CompositorImpl::new(script_chan.clone(), copy *opts, prof_chan.clone());
 
     // Send each file to render then wait for keypress
     let (keypress_from_compositor, keypress_to_engine) = comm::stream();
@@ -152,7 +155,9 @@ fn run(opts: &Opts) {
                                     script_port,
                                     script_chan,
                                     resource_task,
-                                    image_cache_task);
+                                    image_cache_task,
+                                    prof_port,
+                                    prof_chan);
 
     for opts.urls.each |filename| {
         let url = make_url(copy *filename, None);

src/components/servo/util/mod.rs

@@ -3,7 +3,6 @@
  * file, You can obtain one at http://mozilla.org/MPL/2.0/. */
 
 pub use servo_util::cache;
-pub use servo_util::time;
 
 pub mod task;