cc:: Add LatencyQuery logic back into OutputSurface.

cc/output/output_surface.cc

Index: cc/output/output_surface.cc
diff --git a/cc/output/output_surface.cc b/cc/output/output_surface.cc
index a0efb6fdb28addad45dc62f4ee3c097320a334ad..da1a7f4eaeaca1a4a10eebcd2bcd668cb9d84ca4 100644
--- a/cc/output/output_surface.cc
+++ b/cc/output/output_surface.cc
@@ -21,6 +21,7 @@
 #include "cc/output/managed_memory_policy.h"
 #include "cc/output/output_surface_client.h"
 #include "cc/scheduler/delay_based_time_source.h"
+#include "gpu/GLES2/gl2extchromium.h"
 #include "gpu/command_buffer/client/context_support.h"
 #include "gpu/command_buffer/client/gles2_interface.h"
 #include "ui/gfx/frame_time.h"
@@ -31,6 +32,12 @@ using std::set;
 using std::string;
 using std::vector;
 
+namespace {
+
+const size_t kGpuLatencyHistorySize = 60;
+const double kGpuLatencyEstimationPercentile = 100.0;

[brianderson, 2014/09/10 22:36:34]

In other cases where we record history, we've seen that taking the worst case
isn't ideal.

Let's change the percentile to be 90 as our starting point this time.

+}
+
 namespace cc {
 
 OutputSurface::OutputSurface(
@@ -39,7 +46,8 @@ OutputSurface::OutputSurface(
       context_provider_(context_provider),
       device_scale_factor_(-1),
       external_stencil_test_enabled_(false),
-      weak_ptr_factory_(this) {
+      weak_ptr_factory_(this),
+      gpu_latency_history_(kGpuLatencyHistorySize) {
 }
 
 OutputSurface::OutputSurface(scoped_ptr<SoftwareOutputDevice> software_device)
@@ -47,7 +55,8 @@ OutputSurface::OutputSurface(scoped_ptr<SoftwareOutputDevice> software_device)
       software_device_(software_device.Pass()),
       device_scale_factor_(-1),
       external_stencil_test_enabled_(false),
-      weak_ptr_factory_(this) {
+      weak_ptr_factory_(this),
+      gpu_latency_history_(kGpuLatencyHistorySize) {
 }
 
 OutputSurface::OutputSurface(
@@ -58,7 +67,8 @@ OutputSurface::OutputSurface(
       software_device_(software_device.Pass()),
       device_scale_factor_(-1),
       external_stencil_test_enabled_(false),
-      weak_ptr_factory_(this) {
+      weak_ptr_factory_(this),
+      gpu_latency_history_(kGpuLatencyHistorySize) {
 }
 
 void OutputSurface::CommitVSyncParameters(base::TimeTicks timebase,
@@ -84,6 +94,8 @@ void OutputSurface::ReclaimResources(const CompositorFrameAck* ack) {
 
 void OutputSurface::DidLoseOutputSurface() {
   TRACE_EVENT0("cc", "OutputSurface::DidLoseOutputSurface");
+  pending_gpu_latency_query_ids_.clear();
+  available_gpu_latency_query_ids_.clear();
   client_->DidLoseOutputSurface();
 }
 
@@ -181,6 +193,16 @@ void OutputSurface::ReleaseContextProvider() {
 
 void OutputSurface::ResetContext3d() {
   if (context_provider_.get()) {
+    while (!pending_gpu_latency_query_ids_.empty()) {
+      unsigned query_id = pending_gpu_latency_query_ids_.front();
+      pending_gpu_latency_query_ids_.pop_front();
+      context_provider_->ContextGL()->DeleteQueriesEXT(1, &query_id);
+    }
+    while (!available_gpu_latency_query_ids_.empty()) {
+      unsigned query_id = available_gpu_latency_query_ids_.front();
+      available_gpu_latency_query_ids_.pop_front();
+      context_provider_->ContextGL()->DeleteQueriesEXT(1, &query_id);
+    }
     context_provider_->SetLostContextCallback(
         ContextProvider::LostContextCallback());
     context_provider_->SetMemoryPolicyChangedCallback(
@@ -236,6 +258,7 @@ void OutputSurface::SwapBuffers(CompositorFrame* frame) {
   DCHECK(context_provider_.get());
   DCHECK(frame->gl_frame_data);
 
+  UpdateAndMeasureGpuLatency();
   if (frame->gl_frame_data->sub_buffer_rect ==
       gfx::Rect(frame->gl_frame_data->size)) {
     context_provider_->ContextSupport()->Swap();
@@ -247,6 +270,76 @@ void OutputSurface::SwapBuffers(CompositorFrame* frame) {
   client_->DidSwapBuffers();
 }
 
+base::TimeDelta OutputSurface::GpuLatencyEstimate() {
+  if (context_provider_.get() && !capabilities_.adjust_deadline_for_parent)
+    return gpu_latency_history_.Percentile(kGpuLatencyEstimationPercentile);
+  else
+    return base::TimeDelta();
+}
+
+void OutputSurface::UpdateAndMeasureGpuLatency() {
+  // We only care about GPU latency for surfaces that do not have a parent
+  // compositor, since surfaces that do have a parent compositor can use
+  // mailboxes or delegated rendering to send frames to their parent without
+  // incurring GPU latency.
+  if (capabilities_.adjust_deadline_for_parent)
+    return;
+
+  while (pending_gpu_latency_query_ids_.size()) {

[brianderson, 2014/09/10 22:36:35]

Can you add a comment indicating this loop collects completed latency queries.

+    unsigned query_id = pending_gpu_latency_query_ids_.front();
+    unsigned query_complete = 1;
+    context_provider_->ContextGL()->GetQueryObjectuivEXT(
+        query_id, GL_QUERY_RESULT_AVAILABLE_EXT, &query_complete);
+    if (!query_complete)
+      break;
+
+    unsigned value = 0;
+    context_provider_->ContextGL()->GetQueryObjectuivEXT(
+        query_id, GL_QUERY_RESULT_EXT, &value);
+    pending_gpu_latency_query_ids_.pop_front();
+    available_gpu_latency_query_ids_.push_back(query_id);
+
+    base::TimeDelta latency = base::TimeDelta::FromMicroseconds(value);
+    base::TimeDelta latency_estimate = GpuLatencyEstimate();
+    gpu_latency_history_.InsertSample(latency);
+
+    base::TimeDelta latency_overestimate;
+    base::TimeDelta latency_underestimate;
+    if (latency > latency_estimate)
+      latency_underestimate = latency - latency_estimate;
+    else
+      latency_overestimate = latency_estimate - latency;
+    UMA_HISTOGRAM_CUSTOM_TIMES("Renderer.GpuLatency",
+                               latency,
+                               base::TimeDelta::FromMilliseconds(1),
+                               base::TimeDelta::FromMilliseconds(100),
+                               50);
+    UMA_HISTOGRAM_CUSTOM_TIMES("Renderer.GpuLatencyUnderestimate",
+                               latency_underestimate,
+                               base::TimeDelta::FromMilliseconds(1),
+                               base::TimeDelta::FromMilliseconds(100),
+                               50);
+    UMA_HISTOGRAM_CUSTOM_TIMES("Renderer.GpuLatencyOverestimate",
+                               latency_overestimate,
+                               base::TimeDelta::FromMilliseconds(1),
+                               base::TimeDelta::FromMilliseconds(100),
+                               50);
+  }
+
+  unsigned gpu_latency_query_id;

[brianderson, 2014/09/10 22:36:35]

A comment would hlep here too.

+  if (available_gpu_latency_query_ids_.size()) {
+    gpu_latency_query_id = available_gpu_latency_query_ids_.front();
+    available_gpu_latency_query_ids_.pop_front();
+  } else {
+    context_provider_->ContextGL()->GenQueriesEXT(1, &gpu_latency_query_id);
+  }
+
+  context_provider_->ContextGL()->BeginQueryEXT(GL_LATENCY_QUERY_CHROMIUM,

[brianderson, 2014/09/10 22:36:35]

And here.

+                                                gpu_latency_query_id);
+  context_provider_->ContextGL()->EndQueryEXT(GL_LATENCY_QUERY_CHROMIUM);
+  pending_gpu_latency_query_ids_.push_back(gpu_latency_query_id);
+}
+
 void OutputSurface::PostSwapBuffersComplete() {
   base::MessageLoop::current()->PostTask(
       FROM_HERE,