Report LatencyInfo through trace buffer

content/browser/renderer_host/render_widget_host_impl.cc

Index: content/browser/renderer_host/render_widget_host_impl.cc
diff --git a/content/browser/renderer_host/render_widget_host_impl.cc b/content/browser/renderer_host/render_widget_host_impl.cc
index c0a44a2359433de9b7ca6cd23613fbf35bcf53b7..86fffbc0c4dcbaf492d6f275a73f31cd91aaafcf 100644
--- a/content/browser/renderer_host/render_widget_host_impl.cc
+++ b/content/browser/renderer_host/render_widget_host_impl.cc
@@ -1164,10 +1164,10 @@ ui::LatencyInfo RenderWidgetHostImpl::CreateRWHLatencyInfoIfNotExist(
     info = *original;
   // In Aura, gesture event will already carry its original touch event's
   // INPUT_EVENT_LATENCY_RWH_COMPONENT.
-  if (!info.FindLatency(ui::INPUT_EVENT_LATENCY_RWH_COMPONENT,
+  if (!info.FindLatency(ui::INPUT_EVENT_LATENCY_BEGIN_RWH_COMPONENT,
                         GetLatencyComponentId(),
                         NULL)) {
-    info.AddLatencyNumber(ui::INPUT_EVENT_LATENCY_RWH_COMPONENT,
+    info.AddLatencyNumber(ui::INPUT_EVENT_LATENCY_BEGIN_RWH_COMPONENT,
                           GetLatencyComponentId(),
                           ++last_input_number_);
   }
@@ -2188,18 +2188,33 @@ void RenderWidgetHostImpl::OnKeyboardEventAck(
 
 void RenderWidgetHostImpl::OnWheelEventAck(
     const WebKit::WebMouseWheelEvent& wheel_event,
-    InputEventAckState ack_result) {
+    InputEventAckState ack_result,
+    ui::LatencyInfo* latency) {
+  if (!latency->FindLatency(
+          ui::INPUT_EVENT_LATENCY_RENDERING_SCHEDULED_COMPONENT, 0, NULL)) {
+    // MouseWheelEvent latency ends when it is acked but does not cause any
+    // rendering scheduled.
+    latency->AddLatencyNumber(

[jdduke (slow), 2013/10/08 16:28:08]

Please revert the arg changes and just copy the ui::LatencyInfo if necessary
here (within the if).

[Yufeng Shen (Slow to review), 2013/10/08 19:35:59]

Done.

+        ui::INPUT_EVENT_LATENCY_TERMINATED_MOUSE_COMPONENT, 0, 0);
+  }
   const bool processed = (INPUT_EVENT_ACK_STATE_CONSUMED == ack_result);
   if (overscroll_controller_)
     overscroll_controller_->ReceivedEventACK(wheel_event, processed);
-
   if (!processed && !is_hidden() && view_)
     view_->UnhandledWheelEvent(wheel_event);
 }
 
 void RenderWidgetHostImpl::OnGestureEventAck(
     const WebKit::WebGestureEvent& event,
-    InputEventAckState ack_result) {
+    InputEventAckState ack_result,
+    ui::LatencyInfo* latency) {

[jdduke (slow), 2013/10/08 16:28:08]

Same as above.

[Yufeng Shen (Slow to review), 2013/10/08 19:35:59]

Done.

+  if (!latency->FindLatency(
+          ui::INPUT_EVENT_LATENCY_RENDERING_SCHEDULED_COMPONENT, 0, NULL)) {
+    // GestureEvent latency ends when it is acked but does not cause any
+    // rendering scheduled.
+    latency->AddLatencyNumber(
+        ui::INPUT_EVENT_LATENCY_TERMINATED_GESTURE_COMPONENT, 0 ,0);
+  }
   const bool processed = (INPUT_EVENT_ACK_STATE_CONSUMED == ack_result);
   if (overscroll_controller_)
     overscroll_controller_->ReceivedEventACK(event, processed);
@@ -2209,11 +2224,17 @@ void RenderWidgetHostImpl::OnGestureEventAck(
 }
 
 void RenderWidgetHostImpl::OnTouchEventAck(
-    const TouchEventWithLatencyInfo& event,
-    InputEventAckState ack_result) {
-  ComputeTouchLatency(event.latency);
+    const WebKit::WebTouchEvent& event,
+    InputEventAckState ack_result,
+    ui::LatencyInfo* latency) {
+  // TouchEvent latency does not end when acked since it could later on
+  // become gesture events.
+  latency->AddLatencyNumber(ui::INPUT_EVENT_LATENCY_ACKED_TOUCH_COMPONENT,

[jdduke (slow), 2013/10/08 16:28:08]

Ditto.

[Yufeng Shen (Slow to review), 2013/10/08 19:35:59]

Done.

+                            0, 0);
+  ComputeTouchLatency(*latency);
   if (view_)
-    view_->ProcessAckedTouchEvent(event, ack_result);
+    view_->ProcessAckedTouchEvent(TouchEventWithLatencyInfo(event, *latency),
+                                  ack_result);
 }
 
 void RenderWidgetHostImpl::OnUnexpectedEventAck(UnexpectedEventAckType type) {
@@ -2484,7 +2505,7 @@ void RenderWidgetHostImpl::ComputeTouchLatency(
   if (!latency_info.FindLatency(ui::INPUT_EVENT_LATENCY_UI_COMPONENT,
                                 0,
                                 &ui_component) ||
-      !latency_info.FindLatency(ui::INPUT_EVENT_LATENCY_RWH_COMPONENT,
+      !latency_info.FindLatency(ui::INPUT_EVENT_LATENCY_BEGIN_RWH_COMPONENT,
                                 GetLatencyComponentId(),
                                 &rwh_component))
     return;
@@ -2503,7 +2524,7 @@ void RenderWidgetHostImpl::ComputeTouchLatency(
       20000,
       100);
 
-  if (latency_info.FindLatency(ui::INPUT_EVENT_LATENCY_ACKED_COMPONENT,
+  if (latency_info.FindLatency(ui::INPUT_EVENT_LATENCY_ACKED_TOUCH_COMPONENT,
                                0,
                                &acked_component)) {
     DCHECK(acked_component.event_count == 1);
@@ -2526,15 +2547,20 @@ void RenderWidgetHostImpl::ComputeTouchLatency(
 
 void RenderWidgetHostImpl::FrameSwapped(const ui::LatencyInfo& latency_info) {
   ui::LatencyInfo::LatencyComponent rwh_component;
-  if (!latency_info.FindLatency(ui::INPUT_EVENT_LATENCY_RWH_COMPONENT,
+  ui::LatencyInfo::LatencyComponent swap_component;
+  if (!latency_info.FindLatency(ui::INPUT_EVENT_LATENCY_BEGIN_RWH_COMPONENT,
                                 GetLatencyComponentId(),
-                                &rwh_component))
+                                &rwh_component) ||
+      !latency_info.FindLatency(
+          ui::INPUT_EVENT_LATENCY_TERMINATED_FRAME_SWAP_COMPONENT,
+          0, &swap_component)) {
     return;
+  }
 
   rendering_stats_.input_event_count += rwh_component.event_count;
   rendering_stats_.total_input_latency +=
       rwh_component.event_count *
-      (latency_info.swap_timestamp - rwh_component.event_time);
+      (swap_component.event_time - rwh_component.event_time);
 
   ui::LatencyInfo::LatencyComponent original_component;
   if (latency_info.FindLatency(
@@ -2545,7 +2571,7 @@ void RenderWidgetHostImpl::FrameSwapped(const ui::LatencyInfo& latency_info) {
     // created (averaged if there are multiple) to when the scroll gesture
     // results in final frame swap.
     base::TimeDelta delta =
-        latency_info.swap_timestamp - original_component.event_time;
+        swap_component.event_time - original_component.event_time;
     for (size_t i = 0; i < original_component.event_count; i++) {
       UMA_HISTOGRAM_CUSTOM_COUNTS(
           "Event.Latency.TouchToScrollUpdateSwap",
@@ -2557,7 +2583,7 @@ void RenderWidgetHostImpl::FrameSwapped(const ui::LatencyInfo& latency_info) {
     rendering_stats_.scroll_update_count += original_component.event_count;
     rendering_stats_.total_scroll_update_latency +=
         original_component.event_count *
-        (latency_info.swap_timestamp - original_component.event_time);
+        (swap_component.event_time - original_component.event_time);
   }
 
   if (CommandLine::ForCurrentProcess()->HasSwitch(
@@ -2576,7 +2602,7 @@ void RenderWidgetHostImpl::CompositorFrameDrawn(
            latency_info.latency_components.begin();
        b != latency_info.latency_components.end();
        ++b) {
-    if (b->first.first != ui::INPUT_EVENT_LATENCY_RWH_COMPONENT)
+    if (b->first.first != ui::INPUT_EVENT_LATENCY_BEGIN_RWH_COMPONENT)
       continue;
     // Matches with GetLatencyComponentId
     int routing_id = b->first.second & 0xffffffff;