Add UMA/Telemetry stats for end-to-end scroll latency

content/browser/renderer_host/render_widget_host_impl.cc

 // Copyright (c) 2012 The Chromium Authors. All rights reserved.
 // Use of this source code is governed by a BSD-style license that can be
 // found in the LICENSE file.
 
 #include "content/browser/renderer_host/render_widget_host_impl.h"
 
 #include <math.h>
 #include <utility>
 
 #include "base/auto_reset.h"
@@ skipping 1125 matching lines @@
 
   ui::LatencyInfo latency_info;
   // In Aura, gesture event will carry its original touch event's
   // INPUT_EVENT_LATENCY_RWH_COMPONENT. For non-aura platform, we add the
   // INPUT_EVENT_LATENCY_RWH_COMPONENT right here.
   if (!ui_latency.FindLatency(ui::INPUT_EVENT_LATENCY_RWH_COMPONENT,
                               GetLatencyComponentId(),
                               NULL))
     latency_info = NewInputLatencyInfo();
 
-  latency_info.AddLatencyNumber(ui::INPUT_EVENT_LATENCY_INJECTED_RWH_COMPONENT,
-                                GetLatencyComponentId(),
-                                ++last_input_number_);
-  latency_info.MergeWith(ui_latency);
+  WebKit::WebInputEvent::Type type = gesture_event.type;
+  if (type == WebKit::WebInputEvent::GestureScrollBegin ||
+      type == WebKit::WebInputEvent::GestureScrollUpdate ||
+      type == WebKit::WebInputEvent::GestureScrollUpdateWithoutPropagation) {
+    latency_info.AddLatencyNumber(
+        ui::INPUT_EVENT_LATENCY_INJECTED_RWH_COMPONENT,
+        GetLatencyComponentId(),
+        ++last_input_number_);
+    latency_info.MergeWith(ui_latency);

[Rick Byers, 2013/07/10 01:36:30]

Why do we need two different LatencyInfo objects here?  Conceptually I would
have expected that we'd just call ui_latency.AddLatencyNumber and not need
latency_info at all...

[Yufeng Shen (Slow to review), 2013/07/10 15:12:04]

right. it is just that it happens to be coded this way. Originally without
ui_latency, there is only one latency_info = NewInputLatencyInfo() is created
here and passed on. Then there comes the ui_latency, and we need to merge what
is in NewInputLatencyInfo() into ui_latency. We can directly add what's added in
NewInputLatencyInfo() into ui_latency (it just adds RWH_COMPONENT), but since we
are using NewInputLatencyInfo() everywhere, I feel it is better just call
NewInputLatencyInfo() and merge the result with ui_latency. 

[Rick Byers, 2013/07/10 15:31:35]

Ok, I see.  But now that you're only conditionally merging ui_latency into
latency_info, doesn't that mean in the non-gesture cases the data in ui_latency
is getting dropped on the floor?  So I think you at least want to merge it in
outside the if block.

It would be clearer to me if we refactored NewInputLatencyInfo to a function
that adds the RWH_COMPONENT to an existing latency info so we're always either
creating or extending a LatencyInfo.

+  }
 
   if (!IsInOverscrollGesture() &&
       !gesture_event_filter_->ShouldForward(
           GestureEventWithLatencyInfo(gesture_event, latency_info))) {
     if (overscroll_controller_.get())
       overscroll_controller_->DiscardingGestureEvent(gesture_event);
     return;
   }
 
   ForwardInputEvent(gesture_event, sizeof(WebGestureEvent),
@@ skipping 1487 matching lines @@
         1000000,
         100);
   }
 
   if (CommandLine::ForCurrentProcess()->HasSwitch(
           switches::kEnableGpuBenchmarking))
     Send(new ViewMsg_SetBrowserRenderingStats(routing_id_, rendering_stats_));
 }
 
 void RenderWidgetHostImpl::FrameSwapped(const ui::LatencyInfo& latency_info) {
-  ui::LatencyInfo::LatencyMap::const_iterator l =
-      latency_info.latency_components.find(std::make_pair(
-          ui::INPUT_EVENT_LATENCY_RWH_COMPONENT, GetLatencyComponentId()));
-  if (l == latency_info.latency_components.end())
+  ui::LatencyInfo::LatencyComponent rwh_component;
+  if (!latency_info.FindLatency(ui::INPUT_EVENT_LATENCY_RWH_COMPONENT,
+                                GetLatencyComponentId(),
+                                &rwh_component))
     return;
 
-  rendering_stats_.input_event_count += l->second.event_count;
+  rendering_stats_.input_event_count += rwh_component.event_count;
   rendering_stats_.total_input_latency +=
-      l->second.event_count *
-      (latency_info.swap_timestamp - l->second.event_time);
+      rwh_component.event_count *
+      (latency_info.swap_timestamp - rwh_component.event_time);
+
+  ui::LatencyInfo::LatencyComponent original_component;
+  if (latency_info.FindLatency(ui::INPUT_EVENT_LATENCY_ORIGINAL_COMPONENT,
+                               0,
+                               &original_component) &&
+      latency_info.FindLatency(ui::INPUT_EVENT_LATENCY_INJECTED_RWH_COMPONENT,
+                               GetLatencyComponentId(),
+                               NULL)) {
+    // This UMA metric tracks the time from when the original touch event is
+    // 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;
+    UMA_HISTOGRAM_CUSTOM_COUNTS(
+        "Event.Latency.Browser.TouchToScroll",
+        delta.InMicroseconds(),
+        0,
+        1000000,
+        100);
+    rendering_stats_.scroll_event_count += original_component.event_count;
+    rendering_stats_.total_scroll_latency +=
+      original_component.event_count *
+      (latency_info.swap_timestamp - original_component.event_time);
+  }
 
   if (CommandLine::ForCurrentProcess()->HasSwitch(
           switches::kEnableGpuBenchmarking))
     Send(new ViewMsg_SetBrowserRenderingStats(routing_id_, rendering_stats_));
 }
 
 void RenderWidgetHostImpl::DidReceiveRendererFrame() {
   view_->DidReceiveRendererFrame();
 }
 
@@ skipping 11 matching lines @@
     int process_id = (b->first.second >> 32) & 0xffffffff;
     RenderWidgetHost* rwh =
         RenderWidgetHost::FromID(process_id, routing_id);
     if (!rwh)
       continue;
     RenderWidgetHostImpl::From(rwh)->FrameSwapped(latency_info);
   }
 }
 
 }  // namespace content