/* This Source Code Form is subject to the terms of the Mozilla Public *License,v.2.0.IfacopyoftheMPLwasnotdistributedwiththis
* file, You can obtain one at http://mozilla.org/MPL/2.0/. */
//! # Overlay profiler //! //! ## Profiler UI string syntax //! //! Comma-separated list of of tokens with trailing and leading spaces trimmed. //! Each tokens can be: //! - A counter name with an optional prefix. The name corresponds to the displayed name (see the //! counters vector below. //! - By default (no prefix) the counter is shown as average + max over half a second. //! - With a '#' prefix the counter is shown as a graph. //! - With a '*' prefix the counter is shown as a change indicator. //! - Some special counters such as GPU time queries have specific visualizations ignoring prefixes. //! - A preset name to append the preset to the UI (see PROFILER_PRESETS). //! - An empty token to insert a bit of vertical space. //! - A '|' token to start a new column. //! - A '_' token to start a new row.
use api::{ColorF, ColorU, RenderCommandInfo}; #[cfg(feature = "debugger")] use api::debugger::{ProfileCounterUpdate, ProfileCounterId}; use glyph_rasterizer::profiler::GlyphRasterizeProfiler; usecrate::renderer::DebugRenderer; usecrate::device::query::GpuTimer; use euclid::{Point2D, Rect, Size2D, vec2, default}; usecrate::internal_types::FastHashMap; usecrate::renderer::{FullFrameStats, init::wr_has_been_initialized}; use api::units::DeviceIntSize; use std::collections::vec_deque::VecDeque; use std::fmt::{Write, Debug}; use std::f32; use std::ops::Range; use std::time::Duration;
fn find_preset(name: &str) -> Option<&'static str> { for preset in PROFILER_PRESETS { if preset.0 == name { return Some(preset.1);
}
}
None
}
// The indices here must match the PROFILE_COUNTERS array (checked at runtime). pubconst FRAME_BUILDING_TIME: usize = 0; pubconst FRAME_VISIBILITY_TIME: usize = 1; pubconst FRAME_PREPARE_TIME: usize = 2; pubconst FRAME_BATCHING_TIME: usize = 3;
// For FPS computation. Updated in update().
frame_timestamps_within_last_second: Vec<u64>,
/// Total number of slow frames on the CPU.
slow_frame_cpu_count: u64, /// Total number of slow frames on the GPU.
slow_frame_gpu_count: u64, /// Slow frames dominated by frame building.
slow_frame_build_count: u64, /// Slow frames dominated by draw call submission.
slow_render_count: u64, /// Slow frames dominated by texture uploads.
slow_upload_count: u64, /// Slow renders with a high number of draw calls.
slow_draw_calls_count: u64, /// Slow renders with a high number of render targets.
slow_targets_count: u64, /// Slow uploads with a high number of blob tiles.
slow_blob_count: u64, /// Slow scrolling or animation frame after a scene build.
slow_scroll_after_scene_count: u64,
// Not in the list below: // - "GPU time queries" shows the details of the GPU time queries if selected as a graph. // - "GPU cache bars" shows some info about the GPU cache.
// TODO: This should be a global variable but to keep things readable we need to be able to // use match in const fn which isn't supported by the current rustc version in gecko's build // system. let profile_counters = &[
float("Frame building", "ms", FRAME_BUILDING_TIME, expected(0.0..6.0).avg(0.0..3.0)),
float("Visibility", "ms", FRAME_VISIBILITY_TIME, expected(0.0..3.0).avg(0.0..2.0)),
float("Prepare", "ms", FRAME_PREPARE_TIME, expected(0.0..3.0).avg(0.0..2.0)),
float("Batching", "ms", FRAME_BATCHING_TIME, expected(0.0..3.0).avg(0.0..2.0)),
/// Sum a few counters and if the total amount is larger than a threshold, update /// a specific counter. /// /// This is useful to monitor slow frame and slow transactions. fn update_slow_event(&mutself, dst_counter: usize, counters: &[usize], threshold: f64) -> bool { letmut total = 0.0; for &counter in counters { ifself.counters[counter].value.is_finite() {
total += self.counters[counter].value;
}
}
if total > threshold { self.counters[dst_counter].set(total); returntrue;
}
false
}
fn classify_slow_cpu_frame(&mutself) { let is_apz = self.counters[RENDER_REASON_ANIMATED_PROPERTY].value > 0.5
|| self.counters[RENDER_REASON_APZ].value > 0.5; if !is_apz { // Only consider slow frames affecting scrolling for now. return;
}
let frame = CpuFrameTimings::new(&self.counters); self.slow_scroll_frames.push(frame.to_profiler_frame());
*reasons[0].1 += 1; let reason = reasons[0].2;
std::mem::drop(reasons);
self.slow_frame_cpu_count += 1;
if reason == SLOW_RENDER_COUNT { let draw_calls = self.counters[DRAW_CALLS].value; if draw_calls > 200.0 { self.slow_draw_calls_count += 1;
}
let render_passes = self.counters[COLOR_PASSES].value + self.counters[ALPHA_PASSES].value; if render_passes > 20.0 { self.slow_targets_count += 1;
}
}
if reason == SLOW_UPLOAD_COUNT { let count = self.counters[TEXTURE_UPLOADS].value; let blob_tiles = self.counters[RASTERIZED_BLOB_TILES].value; // This is an approximation: we rasterize blobs for the whole displayport and // only upload blob tiles for the current viewport. That said, the presence of // a high number of blob tiles compared to the total number of uploads is still // a good indication that blob images are the likely cause of the slow upload // time, or at least contributing to it to a large extent. if blob_tiles > count * 0.5 { self.slow_blob_count += 1;
}
}
}
// Call at the end of every frame, after setting the counter values and before drawing the counters. pubfn update(&mutself) { let now = zeitstempel::now(); let update_avg = (now - self.start) > self.avg_over_period; if update_avg { self.start = now;
} let one_second_ago = now - ONE_SECOND_NS; self.frame_timestamps_within_last_second.retain(|t| *t > one_second_ago); self.frame_timestamps_within_last_second.push(now);
let slow_cpu = self.update_slow_event(
SLOW_FRAME,
&[TOTAL_FRAME_CPU_TIME], self.slow_cpu_frame_threshold as f64,
); self.update_slow_event(
SLOW_TXN,
&[DISPLAY_LIST_BUILD_TIME, CONTENT_SEND_TIME, SCENE_BUILD_TIME], 80.0
);
if slow_cpu { self.classify_slow_cpu_frame();
}
let div = 100.0 / self.slow_frame_cpu_count as f64; self.counters[SLOW_FRAME_CPU_COUNT].set(self.slow_frame_cpu_count as f64); self.counters[SLOW_FRAME_GPU_COUNT].set(self.slow_frame_gpu_count as f64); self.counters[SLOW_FRAME_BUILD_COUNT].set(self.slow_frame_build_count as f64 * div); self.counters[SLOW_RENDER_COUNT].set(self.slow_render_count as f64 * div); self.counters[SLOW_UPLOAD_COUNT].set(self.slow_upload_count as f64 * div); self.counters[SLOW_DRAW_CALLS_COUNT].set(self.slow_draw_calls_count as f64 * div); self.counters[SLOW_TARGETS_COUNT].set(self.slow_targets_count as f64 * div); self.counters[SLOW_BLOB_COUNT].set(self.slow_blob_count as f64 * div); self.counters[SLOW_SCROLL_AFTER_SCENE_COUNT].set(self.slow_scroll_after_scene_count as f64 * div);
self.update_total_gpu_mem();
for counter in &mutself.counters {
counter.update(update_avg);
}
}
let gpu_time = ns_to_ms(gpu_time_ns); self.counters[GPU_TIME].set_f64(gpu_time); if gpu_time > 12.0 { self.slow_frame_gpu_count += 1;
}
}
// Find the index of a counter by its name. pubfn index_of(&self, name: &str) -> Option<usize> { self.counters.iter().position(|counter| counter.name == name)
}
// Define the profiler UI, see comment about the syntax at the top of this file. pubfn set_ui(&mutself, names: &str) { letmut selection = Vec::new();
self.append_to_ui(&mut selection, names);
if selection == self.ui { return;
}
for counter in &mutself.counters {
counter.disable_graph();
}
for item in &selection { iflet Item::Graph(idx) = item { self.counters[*idx].enable_graph(self.num_graph_samples);
}
}
let size = Size2D::new(max_samples, 100.0); let line_height = debug_renderer.line_height(); let graph_rect = Rect::new(Point2D::new(x + PROFILE_PADDING, y + PROFILE_PADDING), size); letmut rect = graph_rect.inflate(PROFILE_PADDING, PROFILE_PADDING);
let bx1 = graph_rect.max_x(); let by1 = graph_rect.max_y();
let w = graph_rect.size.width / max_samples; let h = graph_rect.size.height;
let color_t0 = ColorU::new(0, 255, 0, 255); let color_b0 = ColorU::new(0, 180, 0, 255);
let color_t2 = ColorU::new(255, 0, 0, 255); let color_b2 = ColorU::new(180, 0, 0, 255);
if stats.max > 0.0 { for (index, sample) in graph.values.iter().enumerate() { if !sample.is_finite() { // NAN means no sample this frame. continue;
} let sample = *sample as f32; let x1 = bx1 - index as f32 * w; let x0 = x1 - w;
let y0 = by1 - (sample / stats.max as f32) as f32 * h; let y1 = by1;
let (color_top, color_bottom) = if counter.is_unexpected_value(sample as f64) {
(color_t2, color_b2)
} else {
(color_t0, color_b0)
};
// Draw the indicator red instead of blue if is is not within expected ranges. let color = if counter.has_unexpected_value() || counter.has_unexpected_avg_max() {
ColorU::new(255, 20, 20, 255)
} else {
ColorU::new(0, 100, 250, 255)
};
let tx = counter.change_indicator as f32 * width;
debug_renderer.add_quad(
x,
y,
x + 15.0 * width,
y + height,
ColorU::new(0, 0, 0, 150),
ColorU::new(0, 0, 0, 150),
);
debug_renderer.add_quad(
x + tx,
y,
x + tx + width,
y + height,
color,
ColorU::new(25, 25, 25, 255),
);
// If the max time is lower than 16ms, fix the scale // at 16ms so that the graph is easier to interpret. let baseline_ns = 16_000_000.0; // 16ms
max_time = max_time.max(baseline_ns);
letmut tags_present = FastHashMap::default();
for frame in &frame_collection.frames { let y1 = y0 + GRAPH_FRAME_HEIGHT;
letmut current_ns = 0; for sample in &frame.samples { let x0 = graph_rect.origin.x + w * current_ns as f32 / max_time;
current_ns += sample.time_ns; let x1 = graph_rect.origin.x + w * current_ns as f32 / max_time; letmut bottom_color = sample.tag.color;
bottom_color.a *= 0.5;
// If the max time is higher than 16ms, show a vertical line at the // 16ms mark. if max_time > baseline_ns { let x = graph_rect.origin.x + w * baseline_ns as f32 / max_time; let height = frame_collection.frames.len() as f32 * GRAPH_FRAME_HEIGHT;
// Add a legend to see which color correspond to what primitive. const LEGEND_SIZE: f32 = 20.0; const PADDED_LEGEND_SIZE: f32 = 25.0; if !tags_present.is_empty() {
debug_renderer.add_quad(
bounding_rect.max_x() + GRAPH_PADDING,
bounding_rect.origin.y,
bounding_rect.max_x() + GRAPH_PADDING + 200.0,
bounding_rect.origin.y + tags_present.len() as f32 * PADDED_LEGEND_SIZE + GRAPH_PADDING,
BACKGROUND_COLOR,
BACKGROUND_COLOR,
);
}
for (i, (label, &color)) in tags_present.iter().enumerate() { let x0 = bounding_rect.origin.x + bounding_rect.size.width + GRAPH_PADDING * 2.0; let y0 = bounding_rect.origin.y + GRAPH_PADDING + i as f32 * PADDED_LEGEND_SIZE;
column_width = column_width.max(rect.size.width);
y = rect.max_y();
if y > device_size.height as f32 - 100.0 {
max_y = max_y.max(y);
x += column_width + PROFILE_SPACING;
y = y_start;
column_width = default_column_width;
}
}
}
#[cfg(feature = "capture")] pubfn dump_stats(&self, sink: &mutdyn std::io::Write) -> std::io::Result<()> { for counter in &self.counters { if counter.value.is_finite() {
writeln!(sink, "{} {:?}{}", counter.name, counter.value, counter.unit)?;
}
}
Ok(())
}
}
/// Defines the interface for hooking up an external profiler to WR. pubtrait ProfilerHooks : Send + Sync { /// Register a thread with the profiler. fn register_thread(&self, thread_name: &str);
/// Unregister a thread with the profiler. fn unregister_thread(&self);
/// Called at the beginning of a profile scope. fn begin_marker(&self, label: &str);
/// Called at the end of a profile scope. fn end_marker(&self, label: &str);
/// Called to mark an event happening. fn event_marker(&self, label: &str);
/// Called with a duration to indicate a text marker that just ended. Text /// markers allow different types of entries to be recorded on the same row /// in the timeline, by adding labels to the entry. /// /// This variant is also useful when the caller only wants to record events /// longer than a certain threshold, and thus they don't know in advance /// whether the event will qualify. fn add_text_marker(&self, label: &str, text: &str, duration: Duration);
/// Returns true if the current thread is being profiled. fn thread_is_being_profiled(&self) -> bool;
}
/// The current global profiler callbacks, if set by embedder. pubstaticmut PROFILER_HOOKS: Option<&'static dyn ProfilerHooks> = None;
/// Set the profiler callbacks, or None to disable the profiler. /// This function must only ever be called before any WR instances /// have been created, or the hooks will not be set. pubfn set_profiler_hooks(hooks: Option<&'static dyn ProfilerHooks>) { if !wr_has_been_initialized() { unsafe {
PROFILER_HOOKS = hooks;
}
}
}
/// A simple RAII style struct to manage a profile scope. pubstruct ProfileScope {
name: &'static str,
}
/// Register a thread with the Gecko Profiler. pubfn register_thread(thread_name: &str) { unsafe { iflet Some(ref hooks) = PROFILER_HOOKS {
hooks.register_thread(thread_name);
}
}
}
/// Unregister a thread with the Gecko Profiler. pubfn unregister_thread() { unsafe { iflet Some(ref hooks) = PROFILER_HOOKS {
hooks.unregister_thread();
}
}
}
/// Records a marker of the given duration that just ended. pubfn add_text_marker(label: &str, text: &str, duration: Duration) { unsafe { iflet Some(ref hooks) = PROFILER_HOOKS {
hooks.add_text_marker(label, text, duration);
}
}
}
/// Records a marker of the given duration that just ended. pubfn add_event_marker(label: &str) { unsafe { iflet Some(ref hooks) = PROFILER_HOOKS {
hooks.event_marker(label);
}
}
}
/// Returns true if the current thread is being profiled. pubfn thread_is_being_profiled() -> bool { unsafe {
PROFILER_HOOKS.map_or(false, |h| h.thread_is_being_profiled())
}
}
impl ProfileScope { /// Begin a new profile scope pubfn new(name: &'static str) -> Self { unsafe { iflet Some(ref hooks) = PROFILER_HOOKS {
hooks.begin_marker(name);
}
}
///
value: f64, /// Number of samples in the current time slice.
num_samples: u64, /// Sum of the values recorded during the current time slice.
sum: f64, /// The max value in in-progress time slice.
next_max: f64, /// The max value of the previous time slice (displayed).
max: f64, /// The average value of the previous time slice (displayed).
avg: f64, /// Incremented when the counter changes.
change_indicator: u8,
/// A container for profiling information that moves along the rendering pipeline /// and is handed off to the profiler at the end. pubstruct TransactionProfile { pub events: Vec<Event>,
}
/// Similar to end_time, but doesn't panic if not matched with start_time. pubfn end_time_if_started(&mutself, id: usize) -> Option<f64> { iflet Event::Start(start) = self.events[id] { let now = zeitstempel::now(); let time_ns = now - start;
let time_ms = ns_to_ms(time_ns); self.events[id] = Event::Value(time_ms);
pubfn clear(&mutself) { for evt in &mutself.events {
*evt = Event::None;
}
}
}
impl GlyphRasterizeProfiler for TransactionProfile { fn start_time(&mutself) { let id = GLYPH_RESOLVE_TIME; let ns = zeitstempel::now(); self.events[id] = Event::Start(ns);
}
fn end_time(&mutself) -> f64 { let id = GLYPH_RESOLVE_TIME; self.end_time_if_started(id).unwrap()
}
fn set(&mutself, value: f64) { let id = RASTERIZED_GLYPHS; self.set_f64(id, value);
}
}
Die Informationen auf dieser Webseite wurden
nach bestem Wissen sorgfältig zusammengestellt. Es wird jedoch weder Vollständigkeit, noch Richtigkeit,
noch Qualität der bereit gestellten Informationen zugesichert.
Bemerkung:
Die farbliche Syntaxdarstellung und die Messung sind noch experimentell.