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 ac3915ed9f2fda4b8be61dfd2216c7ef6b08539b..d958a4083b9c8e76e34557d0cb69f24bcb42d871 100644
--- a/content/browser/renderer_host/render_widget_host_impl.cc
+++ b/content/browser/renderer_host/render_widget_host_impl.cc
@@ -2186,30 +2186,34 @@ void RenderWidgetHostImpl::OnKeyboardEventAck(
 }
 
 void RenderWidgetHostImpl::OnWheelEventAck(
-    const WebKit::WebMouseWheelEvent& wheel_event,
+    const MouseWheelEventWithLatencyInfo& event,

[jdduke (slow), 2013/10/01 23:45:31]

See my comment below about making Report() const.  That will eliminate some of
the LatencyInfo copying.

[Yufeng Shen (Slow to review), 2013/10/04 00:29:51]

As to Nat's suggestion, removed the Report() function and move the logic into
AddLatencyNumber(component_type) that if the component_type is terminal
component, dump the latency info into trace buffer. AddLatencyNumber() is
non-const so I change the OnXXXEventAck() signature to be 
OnXXXEventAck(WebXXXEevet, ack_result, ui::LatencyInfo* latency)

so we can call latency->AddLatencyNumber().

Bundling const WebInputEvent with non-const latencyinfo into one const
XXXEventWithLatencyInfo is causing all the constness/copying problem. So
separate them.

     InputEventAckState ack_result) {
+  ui::LatencyInfo latency = event.latency;
+  latency.Report(ui::INPUT_EVENT_LATENCY_ACKED_MOUSE_COMPONENT);
   const bool processed = (INPUT_EVENT_ACK_STATE_CONSUMED == ack_result);
   if (overscroll_controller_)
-    overscroll_controller_->ReceivedEventACK(wheel_event, processed);
-
+    overscroll_controller_->ReceivedEventACK(event.event, processed);
   if (!processed && !is_hidden() && view_)
-    view_->UnhandledWheelEvent(wheel_event);
+    view_->UnhandledWheelEvent(event.event);
 }
 
 void RenderWidgetHostImpl::OnGestureEventAck(
-    const WebKit::WebGestureEvent& event,
+    const GestureEventWithLatencyInfo& event,
     InputEventAckState ack_result) {
+  ui::LatencyInfo latency = event.latency;
+  latency.Report(ui::INPUT_EVENT_LATENCY_ACKED_GESTURE_COMPONENT);
   const bool processed = (INPUT_EVENT_ACK_STATE_CONSUMED == ack_result);
   if (overscroll_controller_)
-    overscroll_controller_->ReceivedEventACK(event, processed);
-
+    overscroll_controller_->ReceivedEventACK(event.event, processed);
   if (view_)
-    view_->GestureEventAck(event.type, ack_result);
+    view_->GestureEventAck(event.event.type, ack_result);
 }
 
 void RenderWidgetHostImpl::OnTouchEventAck(
     const TouchEventWithLatencyInfo& event,
     InputEventAckState ack_result) {
+  ui::LatencyInfo* latency = const_cast<ui::LatencyInfo*>(&(event.latency));

[jdduke (slow), 2013/10/01 23:45:31]

Again, if Report() was const we could do away with the const_cast here.

[Yufeng Shen (Slow to review), 2013/10/04 00:29:51]

ditto

[jdduke (slow), 2013/10/04 02:22:19]

Sorry, I didn't mean to say we should start passing non-const ui::LatencyInfo
pointers around.  I was more so wondering why in
OnWheelEventAck/OnGestureEventAck you copied the ui::LatencyInfo, but in
OnGestureEventAck you were modifying it in-place?  I was fine with the copying
before, it was really just the const_cast'ing =/ 

[Yufeng Shen (Slow to review), 2013/10/04 18:03:02]

So in the new patch I switch to passing both const WebInputEvent& and
ui::LatencyInfo* for all onGesture/Wheel/TouchEventAck. 
The main problem is that we need to call a non-const method on LatencyInfo
but the XXXEventWithLatencyInfo is passed around as const&, so either
I do a copy of the LatencyInfo and call the non-const method on the copy
or I separate the LatencyInfo from the WebInputEvent and directly call
the non-const method on the ui::LatencyInfo*

Though either way is perfect :(

+  latency->Report(ui::INPUT_EVENT_LATENCY_ACKED_TOUCH_COMPONENT);
   ComputeTouchLatency(event.latency);
   if (view_)
     view_->ProcessAckedTouchEvent(event, ack_result);
@@ -2513,7 +2517,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);
@@ -2536,15 +2540,19 @@ void RenderWidgetHostImpl::ComputeTouchLatency(
 
 void RenderWidgetHostImpl::FrameSwapped(const ui::LatencyInfo& latency_info) {
   ui::LatencyInfo::LatencyComponent rwh_component;

[jdduke (slow), 2013/10/01 23:45:31]

Hmm, I thought we had moved these calculations/updates
(ComputeTouchLatency/FrameSwapped) to the BrowserRenderingStats object? Maybe
that was a separate patch?

[Yufeng Shen (Slow to review), 2013/10/04 00:29:51]

Yeah, I wasn't able to land that. But eventually we will get rid of this
function entirely once we convert to the trace base approach: whenever we think
the latencyinfo is done we dump the latencyinfo into trace buffer and we can in
telemetry gather these latencyinfo and do analysis on them.

+  ui::LatencyInfo::LatencyComponent swap_component;
   if (!latency_info.FindLatency(ui::INPUT_EVENT_LATENCY_RWH_COMPONENT,
                                 GetLatencyComponentId(),
-                                &rwh_component))
+                                &rwh_component) ||
+      !latency_info.FindLatency(ui::INPUT_EVENT_LATENCY_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(
@@ -2555,7 +2563,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",
@@ -2567,7 +2575,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(