Bug 1532810 - Report long-running GL calls to the profiler. r=gw

Differential Revision: https://phabricator.services.mozilla.com/D22202

gfx/layers/wr/WebRenderBridgeParent.cpp

@@ -15,6 +15,7 @@
 #include "GLContextProvider.h"
 #include "nsExceptionHandler.h"
 #include "mozilla/Range.h"
+#include "mozilla/UniquePtr.h"
 #include "mozilla/layers/AnimationHelper.h"
 #include "mozilla/layers/APZSampler.h"
 #include "mozilla/layers/APZUpdater.h"
@@ -64,6 +65,25 @@ void gecko_profiler_end_marker(const char* name) {
 #endif
 }
 
+void gecko_profiler_add_text_marker(const char* name, const char* text_bytes, size_t text_len, uint64_t microseconds) {
+#ifdef MOZ_GECKO_PROFILER
+  if (profiler_thread_is_being_profiled()) {
+    auto now = mozilla::TimeStamp::Now();
+    auto start = now - mozilla::TimeDuration::FromMicroseconds(microseconds);
+    profiler_add_text_marker(
+        name, nsDependentCString(text_bytes, text_len), JS::ProfilingCategoryPair::GRAPHICS, start, now);
+  }
+#endif
+}
+
+bool gecko_profiler_thread_is_being_profiled() {
+#ifdef MOZ_GECKO_PROFILER
+  return profiler_thread_is_being_profiled();
+#else
+  return false;
+#endif
+}
+
 bool is_glcontext_egl(void* glcontext_ptr) {
   MOZ_ASSERT(glcontext_ptr);
 

gfx/webrender_bindings/src/bindings.rs

@@ -16,6 +16,7 @@ use std::ops::Range;
 use std::os::raw::{c_void, c_char, c_float};
 #[cfg(target_os = "android")]
 use std::os::raw::{c_int};
+use std::time::Duration;
 use gleam::gl;
 
 use webrender::api::*;
@@ -757,6 +758,9 @@ pub unsafe extern "C" fn wr_pipeline_info_delete(_info: WrPipelineInfo) {
 extern "C" {
     pub fn gecko_profiler_start_marker(name: *const c_char);
     pub fn gecko_profiler_end_marker(name: *const c_char);
+    pub fn gecko_profiler_add_text_marker(
+        name: *const c_char, text_bytes: *const c_char, text_len: usize, microseconds: u64);
+    pub fn gecko_profiler_thread_is_being_profiled() -> bool;
 }
 
 /// Simple implementation of the WR ProfilerHooks trait to allow profile
@@ -775,6 +779,19 @@ impl ProfilerHooks for GeckoProfilerHooks {
             gecko_profiler_end_marker(label.as_ptr());
         }
     }
+
+    fn add_text_marker(&self, label: &CStr, text: &str, duration: Duration) {
+        unsafe {
+            // NB: This can be as_micros() once we require Rust 1.33.
+            let micros = duration.subsec_micros() as u64 + duration.as_secs() * 1000 * 1000;
+            let text_bytes = text.as_bytes();
+            gecko_profiler_add_text_marker(label.as_ptr(), text_bytes.as_ptr() as *const c_char, text_bytes.len(), micros);
+        }
+    }
+
+    fn thread_is_being_profiled(&self) -> bool {
+        unsafe { gecko_profiler_thread_is_being_profiled() }
+    }
 }
 
 static PROFILER_HOOKS: GeckoProfilerHooks = GeckoProfilerHooks {};

gfx/webrender_bindings/webrender_ffi.h

@@ -33,6 +33,9 @@ void gecko_profiler_unregister_thread();
 
 void gecko_profiler_start_marker(const char* name);
 void gecko_profiler_end_marker(const char* name);
+void gecko_profiler_add_text_marker(
+    const char* name, const char* text_ptr, size_t text_len, uint64_t microseconds);
+bool gecko_profiler_thread_is_being_profiled();
 
 // IMPORTANT: Keep this synchronized with enumerate_interners in
 // gfx/wr/webrender_api

gfx/wr/webrender/src/device/gl.rs

@@ -10,6 +10,7 @@ use euclid::Transform3D;
 use gleam::gl;
 use internal_types::{FastHashMap, LayerIndex, RenderTargetInfo};
 use log::Level;
+use profiler;
 use sha2::{Digest, Sha256};
 use smallvec::SmallVec;
 use std::borrow::Cow;
@@ -28,6 +29,7 @@ use std::slice;
 use std::sync::Arc;
 use std::sync::atomic::{AtomicUsize, Ordering};
 use std::thread;
+use std::time::Duration;
 use webrender_build::shader::ProgramSourceDigest;
 use webrender_build::shader::{parse_shader_source, shader_source_from_file};
 
@@ -919,6 +921,11 @@ enum TexStorageUsage {
 
 pub struct Device {
     gl: Rc<gl::Gl>,
+
+    /// If non-None, |gl| points to a profiling wrapper, and this points to the
+    /// underling Gl instance.
+    base_gl: Option<Rc<gl::Gl>>,
+
     // device state
     bound_textures: [gl::GLuint; 16],
     bound_program: gl::GLuint,
@@ -1235,6 +1242,7 @@ impl Device {
 
         Device {
             gl,
+            base_gl: None,
             resource_override_path,
             upload_method,
             inside_frame: false,
@@ -1363,6 +1371,22 @@ impl Device {
         debug_assert!(!self.inside_frame);
         self.inside_frame = true;
 
+        // If our profiler state has changed, apply or remove the profiling
+        // wrapper from our GL context.
+        let being_profiled = profiler::thread_is_being_profiled();
+        let using_wrapper = self.base_gl.is_some();
+        if being_profiled && !using_wrapper {
+            fn note(name: &str, duration: Duration) {
+                profiler::add_text_marker(cstr!("OpenGL Calls"), name, duration);
+            }
+            let threshold = Duration::from_millis(1);
+            let wrapped = gl::ProfilingGl::wrap(self.gl.clone(), threshold, note);
+            let base = mem::replace(&mut self.gl, wrapped);
+            self.base_gl = Some(base);
+        } else if !being_profiled && using_wrapper {
+            self.gl = self.base_gl.take().unwrap();
+        }
+
         // Retrieve the currently set FBO.
         let mut default_read_fbo = [0];
         unsafe {

gfx/wr/webrender/src/profiler.rs

@@ -11,6 +11,7 @@ use renderer::{MAX_VERTEX_TEXTURE_WIDTH, wr_has_been_initialized};
 use std::collections::vec_deque::VecDeque;
 use std::{f32, mem};
 use std::ffi::CStr;
+use std::time::Duration;
 use time::precise_time_ns;
 
 const GRAPH_WIDTH: f32 = 1024.0;
@@ -30,10 +31,22 @@ pub trait ProfilerHooks : Send + Sync {
     /// Called at the end of a profile scope. The label must
     /// be a C string (null terminated).
     fn end_marker(&self, label: &CStr);
+
+    /// 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: &CStr, 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.
-static mut PROFILER_HOOKS: Option<&'static ProfilerHooks> = None;
+pub static mut PROFILER_HOOKS: Option<&'static ProfilerHooks> = None;
 
 /// Set the profiler callbacks, or None to disable the profiler.
 /// This function must only ever be called before any WR instances
@@ -51,6 +64,22 @@ pub struct ProfileScope {
     name: &'static CStr,
 }
 
+/// Records a marker of the given duration that just ended.
+pub fn add_text_marker(label: &CStr, text: &str, duration: Duration) {
+    unsafe {
+        if let Some(ref hooks) = PROFILER_HOOKS {
+            hooks.add_text_marker(label, text, duration);
+        }
+    }
+}
+
+/// Returns true if the current thread is being profiled.
+pub fn thread_is_being_profiled() -> bool {
+    unsafe {
+        PROFILER_HOOKS.map_or(false, |h| h.thread_is_being_profiled())
+    }
+}
+
 impl ProfileScope {
     /// Begin a new profile scope
     pub fn new(name: &'static CStr) -> Self {