Add telemetry to track the time an event spent waiting for the main thread.

content/renderer/render_widget.cc

Index: content/renderer/render_widget.cc
diff --git a/content/renderer/render_widget.cc b/content/renderer/render_widget.cc
index bb06cfe956eaafc0f7e210d0a5f394ea25c9ea6a..b67e469cb52e1f1fd4b016afbfeea6ae3affe226 100644
--- a/content/renderer/render_widget.cc
+++ b/content/renderer/render_widget.cc
@@ -139,6 +139,56 @@ const char* GetEventName(WebInputEvent::Type type) {
 #undef CASE_TYPE
   return "";
 }
+
+void SendToImplThreadLatencyUma(int routing_id,

[nduca, 2013/07/08 20:58:32]

see you're just using the latency info struct but you'er still doing the probe
here.

your uma should be up in the browser process where you're tracking things about
the input events as they're acked by the host process. the renderer really
shouldn't be doing anything.

[varunjain, 2013/07/10 19:32:37]

Hi Nat, while I am looking into how to plumb the latency info back into the
browser, I wanted to ask why is it wrong to do this in the renderer? Especially
because this metric measures latency that exists entirely in the renderer. We
are recording other UMA stats in render_widget, so why is this one not allowed?

+                                const ui::LatencyInfo& latency_info,
+                                WebInputEvent::Type event_type) {
+  ui::LatencyInfo::LatencyComponent dispatch_component;
+  ui::LatencyInfo::LatencyComponent receive_component;
+  if (latency_info.FindLatency(
+          ui::INPUT_EVENT_LATENCY_SENT_FROM_IMPL_THREAD_COMPONENT,
+          routing_id, &dispatch_component) &&
+      latency_info.FindLatency(
+          ui::INPUT_EVENT_LATENCY_RECEIVED_ON_MAIN_THREAD_COMPONENT,
+          routing_id, &receive_component)) {
+    base::TimeDelta delta = receive_component.event_time -
+        dispatch_component.event_time;
+    switch (event_type) {
+      case WebInputEvent::GestureScrollBegin:
+      case WebInputEvent::GestureScrollUpdate:
+      case WebInputEvent::GestureScrollUpdateWithoutPropagation:
+        UMA_HISTOGRAM_TIMES(
+            "Event.Latency.ImplThreadToRendererThread.GestureScroll", delta);
+        break;
+      case WebInputEvent::TouchStart:
+      case WebInputEvent::TouchMove:
+        UMA_HISTOGRAM_TIMES(
+            "Event.Latency.ImplThreadToRendererThread.Touch", delta);
+        break;
+      default:
+        break;
+    }
+  }
+}
+
+void UpdateRenderingStatsForAverageImplThreadLatency(
+    int routing_id,
+    const ui::LatencyInfo& latency_info,
+    cc::RenderingStats& stats) {
+  ui::LatencyInfo::LatencyComponent dispatch_component;
+  ui::LatencyInfo::LatencyComponent receive_component;
+  if (latency_info.FindLatency(
+          ui::INPUT_EVENT_LATENCY_SENT_FROM_IMPL_THREAD_COMPONENT,
+          routing_id, &dispatch_component) &&
+      latency_info.FindLatency(
+          ui::INPUT_EVENT_LATENCY_RECEIVED_ON_MAIN_THREAD_COMPONENT,
+          routing_id, &receive_component)) {
+    stats.total_impl_thread_to_main_thread_time +=
+        (receive_component.event_time - dispatch_component.event_time);
+    stats.total_impl_thread_to_main_thread_count++;
+  }
+}
+
 }
 namespace content {
 
@@ -738,6 +788,9 @@ void RenderWidget::OnHandleInputEvent(const WebKit::WebInputEvent* input_event,
     compositor_->SetLatencyInfo(latency_info);
   else
     latency_info_.MergeWith(latency_info);
+  SendToImplThreadLatencyUma(routing_id(), latency_info, input_event->type);
+  UpdateRenderingStatsForAverageImplThreadLatency(routing_id(), latency_info,
+                                                  software_stats_);
 
   base::TimeDelta now = base::TimeDelta::FromInternalValue(
       base::TimeTicks::Now().ToInternalValue());
@@ -2333,6 +2386,10 @@ void RenderWidget::GetRenderingStats(
       software_stats_.total_paint_time;
   stats.rendering_stats.total_pixels_painted +=
       software_stats_.total_pixels_painted;
+  stats.rendering_stats.total_impl_thread_to_main_thread_count +=
+      software_stats_.total_impl_thread_to_main_thread_count;
+  stats.rendering_stats.total_impl_thread_to_main_thread_time +=
+      software_stats_.total_impl_thread_to_main_thread_time;
 }
 
 bool RenderWidget::GetGpuRenderingStats(GpuRenderingStats* stats) const {