diff options
| -rw-r--r-- | components/profile/Cargo.toml | 3 | ||||
| -rw-r--r-- | components/profile/lib.rs | 5 | ||||
| -rw-r--r-- | components/profile/time.rs | 18 | ||||
| -rw-r--r-- | components/profile/trace-dump-epilogue-1.html | 3 | ||||
| -rw-r--r-- | components/profile/trace-dump-epilogue-2.html | 4 | ||||
| -rw-r--r-- | components/profile/trace-dump-prologue-1.html | 5 | ||||
| -rw-r--r-- | components/profile/trace-dump-prologue-2.html | 5 | ||||
| -rw-r--r-- | components/profile/trace-dump.css | 100 | ||||
| -rw-r--r-- | components/profile/trace-dump.js | 504 | ||||
| -rw-r--r-- | components/profile/trace_dump.rs | 79 | ||||
| -rw-r--r-- | components/profile_traits/time.rs | 9 | ||||
| -rw-r--r-- | components/servo/Cargo.lock | 3 | ||||
| -rw-r--r-- | components/servo/lib.rs | 3 | ||||
| -rw-r--r-- | components/util/opts.rs | 20 | ||||
| -rw-r--r-- | ports/cef/Cargo.lock | 3 | ||||
| -rw-r--r-- | ports/gonk/Cargo.lock | 3 | ||||
| -rw-r--r-- | tests/unit/profile/time.rs | 2 |
17 files changed, 758 insertions, 11 deletions
diff --git a/components/profile/Cargo.toml b/components/profile/Cargo.toml index 1088725a8b5..ca7a2dc25cb 100644 --- a/components/profile/Cargo.toml +++ b/components/profile/Cargo.toml @@ -16,6 +16,9 @@ ipc-channel = {git = "https://github.com/servo/ipc-channel"} hbs-pow = "0.2" log = "0.3.5" libc = "0.2" +serde = "0.7" +serde_json = "0.7" +serde_macros = "0.7" time = "0.1.12" [target.'cfg(target_os = "macos")'.dependencies] diff --git a/components/profile/lib.rs b/components/profile/lib.rs index 5885d85588d..da2d03c0a8d 100644 --- a/components/profile/lib.rs +++ b/components/profile/lib.rs @@ -7,6 +7,8 @@ #![feature(iter_arith)] #![feature(plugin)] #![plugin(plugins)] +#![feature(custom_derive)] +#![plugin(serde_macros)] #![deny(unsafe_code)] @@ -22,6 +24,8 @@ extern crate log; extern crate profile_traits; #[cfg(target_os = "linux")] extern crate regex; +extern crate serde; +extern crate serde_json; #[cfg(target_os = "macos")] extern crate task_info; extern crate time as std_time; @@ -32,3 +36,4 @@ mod heartbeats; #[allow(unsafe_code)] pub mod mem; pub mod time; +pub mod trace_dump; diff --git a/components/profile/time.rs b/components/profile/time.rs index 6a1152a2d72..fa02cf51f3d 100644 --- a/components/profile/time.rs +++ b/components/profile/time.rs @@ -12,10 +12,13 @@ use profile_traits::time::{TimerMetadataReflowType, TimerMetadataFrameType}; use std::borrow::ToOwned; use std::cmp::Ordering; use std::collections::BTreeMap; +use std::fs; use std::io::{self, Write}; +use std::path; use std::time::Duration; use std::{thread, f64}; use std_time::precise_time_ns; +use trace_dump::TraceDump; use util::thread::spawn_named; use util::time::duration_from_seconds; @@ -125,10 +128,11 @@ pub struct Profiler { pub port: IpcReceiver<ProfilerMsg>, buckets: ProfilerBuckets, pub last_msg: Option<ProfilerMsg>, + trace: Option<TraceDump>, } impl Profiler { - pub fn create(period: Option<f64>) -> ProfilerChan { + pub fn create(period: Option<f64>, file_path: Option<String>) -> ProfilerChan { let (chan, port) = ipc::channel().unwrap(); match period { Some(period) => { @@ -143,7 +147,11 @@ impl Profiler { }); // Spawn the time profiler. spawn_named("Time profiler".to_owned(), move || { - let mut profiler = Profiler::new(port); + let trace = file_path.as_ref() + .map(path::Path::new) + .map(fs::File::create) + .map(|res| TraceDump::new(res.unwrap())); + let mut profiler = Profiler::new(port, trace); profiler.start(); }); } @@ -206,11 +214,12 @@ impl Profiler { profiler_chan } - pub fn new(port: IpcReceiver<ProfilerMsg>) -> Profiler { + pub fn new(port: IpcReceiver<ProfilerMsg>, trace: Option<TraceDump>) -> Profiler { Profiler { port: port, buckets: BTreeMap::new(), last_msg: None, + trace: trace, } } @@ -235,6 +244,9 @@ impl Profiler { match msg.clone() { ProfilerMsg::Time(k, t, e) => { heartbeats::maybe_heartbeat(&k.0, t.0, t.1, e.0, e.1); + if let Some(ref mut trace) = self.trace { + trace.write_one(&k, t, e); + } let ms = (t.1 - t.0) as f64 / 1000000f64; self.find_or_insert(k, ms); }, diff --git a/components/profile/trace-dump-epilogue-1.html b/components/profile/trace-dump-epilogue-1.html new file mode 100644 index 00000000000..401f8301ee1 --- /dev/null +++ b/components/profile/trace-dump-epilogue-1.html @@ -0,0 +1,3 @@ + ]; + </script> + <script type="text/javascript"> diff --git a/components/profile/trace-dump-epilogue-2.html b/components/profile/trace-dump-epilogue-2.html new file mode 100644 index 00000000000..8380010909d --- /dev/null +++ b/components/profile/trace-dump-epilogue-2.html @@ -0,0 +1,4 @@ + //# sourceURL=trace-dump.js + </script> + </body> +</html> diff --git a/components/profile/trace-dump-prologue-1.html b/components/profile/trace-dump-prologue-1.html new file mode 100644 index 00000000000..7638b8d678a --- /dev/null +++ b/components/profile/trace-dump-prologue-1.html @@ -0,0 +1,5 @@ +<!DOCTYPE html> +<html> + <head> + <meta charset="utf-8" /> + <style> diff --git a/components/profile/trace-dump-prologue-2.html b/components/profile/trace-dump-prologue-2.html new file mode 100644 index 00000000000..e82f833abd6 --- /dev/null +++ b/components/profile/trace-dump-prologue-2.html @@ -0,0 +1,5 @@ + </style> + </head> + <body> + <script> + window.TRACES = [ diff --git a/components/profile/trace-dump.css b/components/profile/trace-dump.css new file mode 100644 index 00000000000..75f9b93f8c3 --- /dev/null +++ b/components/profile/trace-dump.css @@ -0,0 +1,100 @@ +/* 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 http://mozilla.org/MPL/2.0/. */ + +body, html { + display: flex; + flex-direction: column; + margin: 0; + padding: 0; + position: relative; + top: 0; + left: 0; + height: 100%; + width: 100%; + overflow: hidden; +} + +#slider { + height: 50px; + background-color: rgba(210, 210, 210, .5); + overflow: hidden; + box-shadow: 0px 0px 5px #999; + z-index: 10; +} + +#slider-viewport { + background-color: rgba(255, 255, 255, .8); + min-width: 5px; + cursor: grab; + display: inline-block; + height: 100%; +} + +.grabby { + background-color: #000; + width: 3px; + cursor: ew-resize; + height: 100%; + display: inline-block; +} + +.slider-tick { + position: absolute; + height: 50px; + top: 0; + color: #000; + border-left: 1px solid #444; +} + +.traces-tick { + position: absolute; + height: 100%; + top: 50px; + color: #aaa; + border-left: 1px solid #ddd; + z-index: -1; + overflow: hidden; + padding-top: calc(50% - .5em); +} + +#traces { + flex: 1; + overflow-x: hidden; + overflow-y: auto; + flex-direction: column; +} + +.outer { + flex: 1; + margin: 0; + padding: 0; +} + +.outer:hover { + background-color: rgba(255, 255, 200, .7); +} + +.inner { + margin: 0; + padding: 0; + overflow: hidden; + height: 100%; + color: white; + min-width: 1px; + text-align: center; +} + +.tooltip { + display: none; +} + +.outer:hover > .tooltip { + display: block; + position: absolute; + top: 50px; + right: 20px; + background-color: rgba(255, 255, 200, .7); + min-width: 20em; + padding: 1em; +} diff --git a/components/profile/trace-dump.js b/components/profile/trace-dump.js new file mode 100644 index 00000000000..a663f89880f --- /dev/null +++ b/components/profile/trace-dump.js @@ -0,0 +1,504 @@ +/* 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 http://mozilla.org/MPL/2.0/. */ + +/*** State *******************************************************************/ + +window.COLORS = [ + "#0088cc", + "#5b5fff", + "#b82ee5", + "#ed2655", + "#f13c00", + "#d97e00", + "#2cbb0f", + "#0072ab", +]; + +window.MIN_TRACE_TIME = 100000; // .1 ms + +// A class containing the cleaned up trace state. +window.State = (function () { + return class { + constructor() { + // The traces themselves. + this.traces = null; + + // Maximimum and minimum times seen in traces. These get normalized to be + // relative to 0, so after initialization minTime is always 0. + this.minTime = Infinity; + this.maxTime = 0; + + // The current start and end of the viewport selection. + this.startSelection = 0; + this.endSelection = 0; + + // The current width of the window. + this.windowWidth = window.innerWidth; + + // Whether the user is actively grabbing the left or right grabby, or the + // viewport slider. + this.grabbingLeft = false; + this.grabbingRight = false; + this.grabbingSlider = false; + + // Maps category labels to a persistent color so that they are always + // rendered the same color. + this.colorIndex = 0; + this.categoryToColor = Object.create(null); + + this.initialize(); + } + + // Clean up and massage the trace data. + initialize() { + this.traces = TRACES.filter(t => t.endTime - t.startTime >= MIN_TRACE_TIME); + window.TRACES = null; + + this.traces.sort((t1, t2) => { + let cmp = t1.startTime - t2.startTime; + if (cmp !== 0) { + return cmp; + } + + return t1.endTime - t2.endTime; + }); + + this.findMinTime(); + this.normalizeTimes(); + this.removeIdleTime(); + this.findMaxTime(); + + this.startSelection = 3 * this.maxTime / 8; + this.endSelection = 5 * this.maxTime / 8; + } + + // Find the minimum timestamp. + findMinTime() { + this.minTime = this.traces.reduce((min, t) => Math.min(min, t.startTime), + Infinity); + } + + // Find the maximum timestamp. + findMaxTime() { + this.maxTime = this.traces.reduce((max, t) => Math.max(max, t.endTime), + 0); + } + + // Normalize all times to be relative to the minTime and then reset the + // minTime to 0. + normalizeTimes() { + for (let i = 0; i < this.traces.length; i++) { + let trace = this.traces[i]; + trace.startTime -= this.minTime; + trace.endTime -= this.minTime; + } + this.minTime = 0; + } + + // Remove idle time between traces. It isn't useful to see and makes + // visualizing the data more difficult. + removeIdleTime() { + let totalIdleTime = 0; + let lastEndTime = null; + + for (let i = 0; i < this.traces.length; i++) { + let trace = this.traces[i]; + + if (lastEndTime !== null && trace.startTime > lastEndTime) { + totalIdleTime += trace.startTime - lastEndTime; + } + + lastEndTime = trace.endTime; + + trace.startTime -= totalIdleTime; + trace.endTime -= totalIdleTime; + } + } + + // Get the color for the given category, or assign one if no such color + // exists yet. + getColorForCategory(category) { + let result = this.categoryToColor[category]; + if (!result) { + result = COLORS[this.colorIndex++ % COLORS.length]; + this.categoryToColor[category] = result; + } + return result; + } + }; +}()); + +window.state = new State(); + +/*** Utilities ****************************************************************/ + +// Get the closest power of ten to the given number. +window.closestPowerOfTen = n => { + let powerOfTen = 1; + let diff = Math.abs(n - powerOfTen); + + while (true) { + let nextPowerOfTen = powerOfTen * 10; + let nextDiff = Math.abs(n - nextPowerOfTen); + + if (nextDiff > diff) { + return powerOfTen; + } + + diff = nextDiff; + powerOfTen = nextPowerOfTen; + } +}; + +// Select the tick increment for the given range size and maximum number of +// ticks to show for that range. +window.selectIncrement = (range, maxTicks) => { + let increment = closestPowerOfTen(range / 10); + while (range / increment > maxTicks) { + increment *= 2; + } + return increment; +}; + +// Get the category name for the given trace. +window.traceCategory = trace => { + return Object.keys(trace.category)[0]; +}; + +/*** Initial Persistent Element Creation **************************************/ + +document.body.innerHTML = ""; + +window.sliderContainer = document.createElement("div"); +sliderContainer.id = "slider"; +document.body.appendChild(sliderContainer); + +window.leftGrabby = document.createElement("span"); +leftGrabby.className = "grabby"; +sliderContainer.appendChild(leftGrabby); + +window.sliderViewport = document.createElement("span"); +sliderViewport.id = "slider-viewport"; +sliderContainer.appendChild(sliderViewport); + +window.rightGrabby = document.createElement("span"); +rightGrabby.className = "grabby"; +sliderContainer.appendChild(rightGrabby); + +window.tracesContainer = document.createElement("div"); +tracesContainer.id = "traces"; +document.body.appendChild(tracesContainer); + +/*** Listeners ***************************************************************/ + +// Run the given function and render afterwards. +window.withRender = fn => (...args) => { + fn(...args); + render(); +}; + +window.addEventListener("resize", withRender(() => { + state.windowWidth = window.innerWidth; +})); + +window.addEventListener("mouseup", () => { + state.grabbingSlider = state.grabbingLeft = state.grabbingRight = false; +}); + +leftGrabby.addEventListener("mousedown", () => { + state.grabbingLeft = true; +}); + +rightGrabby.addEventListener("mousedown", () => { + state.grabbingRight = true; +}); + +sliderViewport.addEventListener("mousedown", () => { + state.grabbingSlider = true; +}); + +window.addEventListener("mousemove", event => { + let ratio = event.clientX / state.windowWidth; + let relativeTime = ratio * state.maxTime; + let absTime = state.minTime + relativeTime; + absTime = Math.min(state.maxTime, absTime); + absTime = Math.max(state.minTime, absTime); + + if (state.grabbingSlider) { + let delta = event.movementX / state.windowWidth * state.maxTime; + if (delta < 0) { + delta = Math.max(-state.startSelection, delta); + } else { + delta = Math.min(state.maxTime - state.endSelection, delta); + } + + state.startSelection += delta; + state.endSelection += delta; + render(); + } else if (state.grabbingLeft) { + state.startSelection = Math.min(absTime, state.endSelection); + render(); + } else if (state.grabbingRight) { + state.endSelection = Math.max(absTime, state.startSelection); + render(); + } +}); + +sliderContainer.addEventListener("wheel", withRender(event => { + let increment = state.maxTime / 1000; + + state.startSelection -= event.deltaY * increment + state.startSelection = Math.max(0, state.startSelection); + state.startSelection = Math.min(state.startSelection, state.endSelection); + + state.endSelection += event.deltaY * increment; + state.endSelection = Math.min(state.maxTime, state.endSelection); + state.endSelection = Math.max(state.startSelection, state.endSelection); +})); + +/*** Rendering ***************************************************************/ + +// Create a function that calls the given function `fn` only once per animation +// frame. +window.oncePerAnimationFrame = fn => { + let animationId = null; + return () => { + if (animationId !== null) { + return; + } + + animationId = requestAnimationFrame(() => { + fn(); + animationId = null; + }); + }; +}; + +// Only call the given function once per window width resize. +window.oncePerWindowWidth = fn => { + let lastWidth = null; + return () => { + if (state.windowWidth !== lastWidth) { + fn(); + lastWidth = state.windowWidth; + } + }; +}; + +// Top level entry point for rendering. Renders the current `window.state`. +window.render = oncePerAnimationFrame(() => { + renderSlider(); + renderTraces(); +}); + +// Render the slider at the top of the screen. +window.renderSlider = () => { + let selectionDelta = state.endSelection - state.startSelection; + + leftGrabby.style.marginLeft = (state.startSelection / state.maxTime) * state.windowWidth + "px"; + + // -6px because of the 3px width of each grabby. + sliderViewport.style.width = (selectionDelta / state.maxTime) * state.windowWidth - 6 + "px"; + + rightGrabby.style.rightMargin = (state.maxTime - state.endSelection) / state.maxTime + * state.windowWidth + "px"; + + renderSliderTicks(); +}; + +// Render the ticks along the slider overview. +window.renderSliderTicks = oncePerWindowWidth(() => { + let oldTicks = Array.from(document.querySelectorAll(".slider-tick")); + for (let tick of oldTicks) { + tick.remove(); + } + + let increment = selectIncrement(state.maxTime, 20); + let px = increment / state.maxTime * state.windowWidth; + let ms = 0; + for (let i = 0; i < state.windowWidth; i += px) { + let tick = document.createElement("div"); + tick.className = "slider-tick"; + tick.textContent = ms + " ms"; + tick.style.left = i + "px"; + document.body.appendChild(tick); + ms += increment / 1000000; + } +}); + +// Render the individual traces. +window.renderTraces = () => { + renderTracesTicks(); + + let tracesToRender = []; + for (let i = 0; i < state.traces.length; i++) { + let trace = state.traces[i]; + + if (trace.endTime < state.startSelection || trace.startTime > state.endSelection) { + continue; + } + + tracesToRender.push(trace); + } + + // Ensure that we have enouch traces elements. If we have more elements than + // traces we are going to render, then remove some. If we have fewer elements + // than traces we are going to render, then add some. + let rows = Array.from(tracesContainer.querySelectorAll(".outer")); + while (rows.length > tracesToRender.length) { + rows.pop().remove(); + } + while (rows.length < tracesToRender.length) { + let elem = makeTraceTemplate(); + tracesContainer.appendChild(elem); + rows.push(elem); + } + + for (let i = 0; i < tracesToRender.length; i++) { + renderTrace(tracesToRender[i], rows[i]); + } +}; + +// Render the ticks behind the traces. +window.renderTracesTicks = () => { + let oldTicks = Array.from(tracesContainer.querySelectorAll(".traces-tick")); + for (let tick of oldTicks) { + tick.remove(); + } + + let selectionDelta = state.endSelection - state.startSelection; + let increment = selectIncrement(selectionDelta, 10); + let px = increment / selectionDelta * state.windowWidth; + let offset = state.startSelection % increment; + let time = state.startSelection - offset + increment; + + while (time < state.endSelection) { + let tick = document.createElement("div"); + tick.className = "traces-tick"; + tick.textContent = Math.round(time / 1000000) + " ms"; + tick.style.left = (time - state.startSelection) / selectionDelta * state.windowWidth + "px"; + tracesContainer.appendChild(tick); + + time += increment; + } +}; + +// Create the DOM structure for an individual trace. +window.makeTraceTemplate = () => { + let outer = document.createElement("div"); + outer.className = "outer"; + + let inner = document.createElement("div"); + inner.className = "inner"; + + let tooltip = document.createElement("div"); + tooltip.className = "tooltip"; + + let header = document.createElement("h3"); + header.className = "header"; + tooltip.appendChild(header); + + let duration = document.createElement("h4"); + duration.className = "duration"; + tooltip.appendChild(duration); + + let pairs = document.createElement("dl"); + + let timeStartLabel = document.createElement("dt"); + timeStartLabel.textContent = "Start:" + pairs.appendChild(timeStartLabel); + + let timeStartValue = document.createElement("dd"); + timeStartValue.className = "start"; + pairs.appendChild(timeStartValue); + + let timeEndLabel = document.createElement("dt"); + timeEndLabel.textContent = "End:" + pairs.appendChild(timeEndLabel); + + let timeEndValue = document.createElement("dd"); + timeEndValue.className = "end"; + pairs.appendChild(timeEndValue); + + let urlLabel = document.createElement("dt"); + urlLabel.textContent = "URL:"; + pairs.appendChild(urlLabel); + + let urlValue = document.createElement("dd"); + urlValue.className = "url"; + pairs.appendChild(urlValue); + + let iframeLabel = document.createElement("dt"); + iframeLabel.textContent = "iframe?"; + pairs.appendChild(iframeLabel); + + let iframeValue = document.createElement("dd"); + iframeValue.className = "iframe"; + pairs.appendChild(iframeValue); + + let incrementalLabel = document.createElement("dt"); + incrementalLabel.textContent = "Incremental?"; + pairs.appendChild(incrementalLabel); + + let incrementalValue = document.createElement("dd"); + incrementalValue.className = "incremental"; + pairs.appendChild(incrementalValue); + + tooltip.appendChild(pairs); + outer.appendChild(tooltip); + outer.appendChild(inner); + return outer; +}; + +// Render `trace` into the given `elem`. We reuse the trace elements and modify +// them with the new trace that will populate this particular `elem` rather than +// clearing the DOM out and rebuilding it from scratch. Its a bit of a +// performance win when there are a lot of traces being rendered. Funnily +// enough, iterating over the complete set of traces hasn't been a performance +// problem at all and the bottleneck seems to be purely rendering the subset of +// traces we wish to show. +window.renderTrace = (trace, elem) => { + let inner = elem.querySelector(".inner"); + inner.style.width = (trace.endTime - trace.startTime) / (state.endSelection - state.startSelection) + * state.windowWidth + "px"; + inner.style.marginLeft = (trace.startTime - state.startSelection) + / (state.endSelection - state.startSelection) + * state.windowWidth + "px"; + + let category = traceCategory(trace); + inner.textContent = category; + inner.style.backgroundColor = state.getColorForCategory(category); + + let header = elem.querySelector(".header"); + header.textContent = category; + + let duration = elem.querySelector(".duration"); + duration.textContent = (trace.endTime - trace.startTime) / 1000000 + " ms"; + + let timeStartValue = elem.querySelector(".start"); + timeStartValue.textContent = trace.startTime / 1000000 + " ms"; + + let timeEndValue = elem.querySelector(".end"); + timeEndValue.textContent = trace.endTime / 1000000 + " ms"; + + if (trace.metadata) { + let urlValue = elem.querySelector(".url"); + urlValue.textContent = trace.metadata.url; + urlValue.removeAttribute("hidden"); + + let iframeValue = elem.querySelector(".iframe"); + iframeValue.textContent = trace.metadata.iframe.RootWindow ? "No" : "Yes"; + iframeValue.removeAttribute("hidden"); + + let incrementalValue = elem.querySelector(".incremental"); + incrementalValue.textContent = trace.metadata.incremental.Incremental ? "Yes" : "No"; + incrementalValue.removeAttribute("hidden"); + } else { + elem.querySelector(".url").setAttribute("hidden", ""); + elem.querySelector(".iframe").setAttribute("hidden", ""); + elem.querySelector(".incremental").setAttribute("hidden", ""); + } +}; + +render(); diff --git a/components/profile/trace_dump.rs b/components/profile/trace_dump.rs new file mode 100644 index 00000000000..8f53d4a9e37 --- /dev/null +++ b/components/profile/trace_dump.rs @@ -0,0 +1,79 @@ +/* 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 http://mozilla.org/MPL/2.0/. */ + +//! A module for writing time profiler traces out to a self contained HTML file. + +use profile_traits::time::{ProfilerCategory, TimerMetadata}; +use serde_json::{self}; +use std::fs; +use std::io::Write; + +/// An RAII class for writing the HTML trace dump. +pub struct TraceDump { + file: fs::File, +} + +#[derive(Debug, Serialize)] +struct TraceEntry { + category: ProfilerCategory, + metadata: Option<TimerMetadata>, + + #[serde(rename = "startTime")] + start_time: u64, + + #[serde(rename = "endTime")] + end_time: u64, + + #[serde(rename = "startEnergy")] + start_energy: u64, + + #[serde(rename = "endEnergy")] + end_energy: u64, +} + +impl TraceDump { + /// Create a new TraceDump and write the prologue of the HTML file out to + /// disk. + pub fn new(mut file: fs::File) -> TraceDump { + write_prologue(&mut file); + TraceDump { file: file } + } + + /// Write one trace to the trace dump file. + pub fn write_one(&mut self, + category: &(ProfilerCategory, Option<TimerMetadata>), + time: (u64, u64), + energy: (u64, u64)) { + let entry = TraceEntry { + category: category.0, + metadata: category.1.clone(), + start_time: time.0, + end_time: time.1, + start_energy: energy.0, + end_energy: energy.1, + }; + serde_json::to_writer(&mut self.file, &entry).unwrap(); + writeln!(&mut self.file, ",").unwrap(); + } +} + +impl Drop for TraceDump { + /// Write the epilogue of the trace dump HTML file out to disk on + /// destruction. + fn drop(&mut self) { + write_epilogue(&mut self.file); + } +} + +fn write_prologue(file: &mut fs::File) { + writeln!(file, "{}", include_str!("./trace-dump-prologue-1.html")).unwrap(); + writeln!(file, "{}", include_str!("./trace-dump.css")).unwrap(); + writeln!(file, "{}", include_str!("./trace-dump-prologue-2.html")).unwrap(); +} + +fn write_epilogue(file: &mut fs::File) { + writeln!(file, "{}", include_str!("./trace-dump-epilogue-1.html")).unwrap(); + writeln!(file, "{}", include_str!("./trace-dump.js")).unwrap(); + writeln!(file, "{}", include_str!("./trace-dump-epilogue-2.html")).unwrap(); +} diff --git a/components/profile_traits/time.rs b/components/profile_traits/time.rs index 203d2953065..aa01c68efb8 100644 --- a/components/profile_traits/time.rs +++ b/components/profile_traits/time.rs @@ -8,7 +8,7 @@ use energy::read_energy_uj; use ipc_channel::ipc::IpcSender; use self::std_time::precise_time_ns; -#[derive(PartialEq, Clone, PartialOrd, Eq, Ord, Deserialize, Serialize)] +#[derive(PartialEq, Clone, PartialOrd, Eq, Ord, Debug, Deserialize, Serialize)] pub struct TimerMetadata { pub url: String, pub iframe: TimerMetadataFrameType, @@ -35,7 +35,7 @@ pub enum ProfilerMsg { } #[repr(u32)] -#[derive(PartialEq, Clone, PartialOrd, Eq, Ord, Deserialize, Serialize, Debug, Hash)] +#[derive(PartialEq, Clone, Copy, PartialOrd, Eq, Ord, Deserialize, Serialize, Debug, Hash)] pub enum ProfilerCategory { Compositing, LayoutPerform, @@ -78,13 +78,13 @@ pub enum ProfilerCategory { ApplicationHeartbeat, } -#[derive(Clone, PartialEq, Eq, PartialOrd, Ord, Deserialize, Serialize)] +#[derive(Clone, PartialEq, Eq, PartialOrd, Ord, Debug, Deserialize, Serialize)] pub enum TimerMetadataFrameType { RootWindow, IFrame, } -#[derive(Clone, PartialEq, Eq, PartialOrd, Ord, Deserialize, Serialize)] +#[derive(Clone, PartialEq, Eq, PartialOrd, Ord, Debug, Deserialize, Serialize)] pub enum TimerMetadataReflowType { Incremental, FirstReflow, @@ -123,4 +123,3 @@ pub fn send_profile_data(category: ProfilerCategory, (start_time, end_time), (start_energy, end_energy))); } - diff --git a/components/servo/Cargo.lock b/components/servo/Cargo.lock index 6f9538ee228..6f3a16c415c 100644 --- a/components/servo/Cargo.lock +++ b/components/servo/Cargo.lock @@ -1652,6 +1652,9 @@ dependencies = [ "plugins 0.0.1", "profile_traits 0.0.1", "regex 0.1.55 (registry+https://github.com/rust-lang/crates.io-index)", + "serde 0.7.0 (registry+https://github.com/rust-lang/crates.io-index)", + "serde_json 0.7.0 (registry+https://github.com/rust-lang/crates.io-index)", + "serde_macros 0.7.2 (registry+https://github.com/rust-lang/crates.io-index)", "task_info 0.0.1", "time 0.1.34 (registry+https://github.com/rust-lang/crates.io-index)", "util 0.0.1", diff --git a/components/servo/lib.rs b/components/servo/lib.rs index 47c66b97590..42e6706500c 100644 --- a/components/servo/lib.rs +++ b/components/servo/lib.rs @@ -116,7 +116,8 @@ impl Browser { let (compositor_proxy, compositor_receiver) = window.create_compositor_channel(); let supports_clipboard = window.supports_clipboard(); - let time_profiler_chan = profile_time::Profiler::create(opts.time_profiler_period); + let time_profiler_chan = profile_time::Profiler::create(opts.time_profiler_period, + opts.time_profiler_trace_path.clone()); let mem_profiler_chan = profile_mem::Profiler::create(opts.mem_profiler_period); let devtools_chan = opts.devtools_port.map(|port| { devtools::start_server(port) diff --git a/components/util/opts.rs b/components/util/opts.rs index a828925c88e..8ca76e87a20 100644 --- a/components/util/opts.rs +++ b/components/util/opts.rs @@ -17,7 +17,7 @@ use std::env; use std::fs; use std::fs::File; use std::io::{self, Read, Write}; -use std::path::Path; +use std::path::{Path, PathBuf}; use std::process; use std::sync::atomic::{AtomicBool, ATOMIC_BOOL_INIT, Ordering}; use url::{self, Url}; @@ -50,6 +50,10 @@ pub struct Opts { /// cause it to produce output on that interval (`-p`). pub time_profiler_period: Option<f64>, + /// When the profiler is enabled, this is an optional path to dump a self-contained HTML file + /// visualizing the traces as a timeline. + pub time_profiler_trace_path: Option<String>, + /// `None` to disable the memory profiler or `Some` with an interval in seconds to enable it /// and cause it to produce output on that interval (`-m`). pub mem_profiler_period: Option<f64>, @@ -469,6 +473,7 @@ pub fn default_opts() -> Opts { tile_size: 512, device_pixels_per_px: None, time_profiler_period: None, + time_profiler_trace_path: None, mem_profiler_period: None, layout_threads: 1, nonincremental_layout: false, @@ -529,6 +534,9 @@ pub fn from_cmdline_args(args: &[String]) -> ArgumentParsingResult { opts.optopt("", "device-pixel-ratio", "Device pixels per px", ""); opts.optopt("t", "threads", "Number of paint threads", "1"); opts.optflagopt("p", "profile", "Profiler flag and output interval", "10"); + opts.optflagopt("", "profiler-trace-path", + "Path to dump a self-contained HTML timeline of profiler traces", + ""); opts.optflagopt("m", "memory-profile", "Memory profiler flag and output interval", "10"); opts.optflag("x", "exit", "Exit after load flag"); opts.optopt("y", "layout-threads", "Number of threads to use for layout", "1"); @@ -656,6 +664,15 @@ pub fn from_cmdline_args(args: &[String]) -> ArgumentParsingResult { period.parse().unwrap_or_else(|err| args_fail(&format!("Error parsing option: -p ({})", err))) }); + if let Some(ref time_profiler_trace_path) = opt_match.opt_str("profiler-trace-path") { + let mut path = PathBuf::from(time_profiler_trace_path); + path.pop(); + if let Err(why) = fs::create_dir_all(&path) { + error!("Couldn't create/open {:?}: {:?}", + Path::new(time_profiler_trace_path).to_string_lossy(), why); + } + } + let mem_profiler_period = opt_match.opt_default("m", "5").map(|period| { period.parse().unwrap_or_else(|err| args_fail(&format!("Error parsing option: -m ({})", err))) }); @@ -755,6 +772,7 @@ pub fn from_cmdline_args(args: &[String]) -> ArgumentParsingResult { tile_size: tile_size, device_pixels_per_px: device_pixels_per_px, time_profiler_period: time_profiler_period, + time_profiler_trace_path: opt_match.opt_str("profiler-trace-path"), mem_profiler_period: mem_profiler_period, layout_threads: layout_threads, nonincremental_layout: nonincremental_layout, diff --git a/ports/cef/Cargo.lock b/ports/cef/Cargo.lock index 6873ea8ad00..62fdf7ec7f8 100644 --- a/ports/cef/Cargo.lock +++ b/ports/cef/Cargo.lock @@ -1530,6 +1530,9 @@ dependencies = [ "plugins 0.0.1", "profile_traits 0.0.1", "regex 0.1.55 (registry+https://github.com/rust-lang/crates.io-index)", + "serde 0.7.0 (registry+https://github.com/rust-lang/crates.io-index)", + "serde_json 0.7.0 (registry+https://github.com/rust-lang/crates.io-index)", + "serde_macros 0.7.2 (registry+https://github.com/rust-lang/crates.io-index)", "task_info 0.0.1", "time 0.1.34 (registry+https://github.com/rust-lang/crates.io-index)", "util 0.0.1", diff --git a/ports/gonk/Cargo.lock b/ports/gonk/Cargo.lock index 919951afc87..a628302e16b 100644 --- a/ports/gonk/Cargo.lock +++ b/ports/gonk/Cargo.lock @@ -1513,6 +1513,9 @@ dependencies = [ "plugins 0.0.1", "profile_traits 0.0.1", "regex 0.1.55 (registry+https://github.com/rust-lang/crates.io-index)", + "serde 0.7.0 (registry+https://github.com/rust-lang/crates.io-index)", + "serde_json 0.7.0 (registry+https://github.com/rust-lang/crates.io-index)", + "serde_macros 0.7.2 (registry+https://github.com/rust-lang/crates.io-index)", "task_info 0.0.1", "time 0.1.34 (registry+https://github.com/rust-lang/crates.io-index)", "util 0.0.1", diff --git a/tests/unit/profile/time.rs b/tests/unit/profile/time.rs index b3156f40f87..b48e60dc423 100644 --- a/tests/unit/profile/time.rs +++ b/tests/unit/profile/time.rs @@ -7,7 +7,7 @@ use profile_traits::time::ProfilerMsg; #[test] fn time_profiler_smoke_test() { - let chan = time::Profiler::create(None); + let chan = time::Profiler::create(None, None); assert!(true, "Can create the profiler thread"); chan.send(ProfilerMsg::Exit); |