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 1008 matching lines @@
             x, y, 0));
       }
       break;
     case WebMouseEvent::ButtonNone:
       break;
   }
 }
 
 void RenderWidgetHostImpl::ForwardMouseEvent(const WebMouseEvent& mouse_event) {
   ForwardMouseEventWithLatencyInfo(
-      MouseEventWithLatencyInfo(mouse_event, NewInputLatencyInfo()));
+      MouseEventWithLatencyInfo(mouse_event,
+                                CreateRWHLatencyInfoIfNotExist(NULL)));
 }
 
 void RenderWidgetHostImpl::ForwardMouseEventWithLatencyInfo(
     const MouseEventWithLatencyInfo& mouse_event) {
   TRACE_EVENT2("input",
                "RenderWidgetHostImpl::ForwardMouseEventWithLatencyInfo",
                "x", mouse_event.event.x, "y", mouse_event.event.y);
   if (ignore_input_events_ || process_->IgnoreInputEvents())
     return;
 
@@ skipping 13 matching lines @@
       return;
 
   ForwardMouseEventImmediately(mouse_event);
 }
 
 void RenderWidgetHostImpl::OnPointerEventActivate() {
 }
 
 void RenderWidgetHostImpl::ForwardWheelEvent(
     const WebMouseWheelEvent& wheel_event) {
-  ForwardWheelEventWithLatencyInfo(wheel_event, NewInputLatencyInfo());
+  ForwardWheelEventWithLatencyInfo(wheel_event,
+                                   CreateRWHLatencyInfoIfNotExist(NULL));
 }
 
 void RenderWidgetHostImpl::ForwardWheelEventWithLatencyInfo(
     const WebMouseWheelEvent& wheel_event,
     const ui::LatencyInfo& latency_info) {
   TRACE_EVENT0("input",
                "RenderWidgetHostImpl::ForwardWheelEventWithLatencyInfo");
   if (ignore_input_events_ || process_->IgnoreInputEvents())
     return;
 
@@ skipping 53 matching lines @@
   ForwardGestureEventWithLatencyInfo(gesture_event, ui::LatencyInfo());
 }
 
 void RenderWidgetHostImpl::ForwardGestureEventWithLatencyInfo(
     const WebKit::WebGestureEvent& gesture_event,
     const ui::LatencyInfo& ui_latency) {
   TRACE_EVENT0("input", "RenderWidgetHostImpl::ForwardGestureEvent");
   if (ignore_input_events_ || process_->IgnoreInputEvents())
     return;
 
-  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();
+  ui::LatencyInfo latency_info = CreateRWHLatencyInfoIfNotExist(&ui_latency);
 
-  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::GestureScrollUpdate) {

[jbauman, 2013/07/12 00:50:39]

Would it make sense to copy the original timestamp from the
ui::INPUT_EVENT_LATENCY_ORIGINAL_COMPONENT from this LatencyInfo into the
timestamp for the ui::INPUT_EVENT_LATENCY_SCROLL_UPDATE_RWH_COMPONENT, so as to
allow it to track the latency from only these events?

[Yufeng Shen (Slow to review), 2013/07/12 21:12:37]

Added a SCROLL_UPDATE_ORIGINAL_COMPONENT copied from ORIGINAL_COMPONENT so we
can specifically track the latency of scroll update.

+    latency_info.AddLatencyNumber(
+        ui::INPUT_EVENT_LATENCY_SCROLL_UPDATE_RWH_COMPONENT,
+        GetLatencyComponentId(),
+        ++last_input_number_);
+  }
 
   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 124 matching lines @@
     // Put all WebKeyboardEvent objects in a queue since we can't trust the
     // renderer and we need to give something to the HandleKeyboardEvent
     // handler.
     key_queue_.push_back(key_event);
     HISTOGRAM_COUNTS_100("Renderer.KeyboardQueueSize", key_queue_.size());
 
     gesture_event_filter_->FlingHasBeenHalted();
 
     // Only forward the non-native portions of our event.
     ForwardInputEvent(key_event, sizeof(WebKeyboardEvent),
-                      NewInputLatencyInfo(),
+                      CreateRWHLatencyInfoIfNotExist(NULL),
                       is_keyboard_shortcut);
   }
 }
 
 void RenderWidgetHostImpl::SendCursorVisibilityState(bool is_visible) {
   Send(new InputMsg_CursorVisibilityChange(GetRoutingID(), is_visible));
 }
 
 int64 RenderWidgetHostImpl::GetLatencyComponentId() {
   return GetRoutingID() | (static_cast<int64>(GetProcess()->GetID()) << 32);
 }
 
 // static
 void RenderWidgetHostImpl::DisableResizeAckCheckForTesting() {
   g_check_for_pending_resize_ack = false;
 }
 
-ui::LatencyInfo RenderWidgetHostImpl::NewInputLatencyInfo() {
+ui::LatencyInfo RenderWidgetHostImpl::CreateRWHLatencyInfoIfNotExist(
+    const ui::LatencyInfo* original) {
   ui::LatencyInfo info;
-  info.AddLatencyNumber(ui::INPUT_EVENT_LATENCY_RWH_COMPONENT,
+  if (original)
+    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,
                         GetLatencyComponentId(),
-                        ++last_input_number_);
+                        NULL)) {
+    info.AddLatencyNumber(ui::INPUT_EVENT_LATENCY_RWH_COMPONENT,
+                          GetLatencyComponentId(),
+                          ++last_input_number_);
+  }
   return info;
 }
 
 void RenderWidgetHostImpl::SendInputEvent(const WebInputEvent& input_event,
                                           int event_size,
                                           const ui::LatencyInfo& latency_info,
                                           bool is_keyboard_shortcut) {
   DCHECK(latency_info.FindLatency(ui::INPUT_EVENT_LATENCY_RWH_COMPONENT,
                                   GetLatencyComponentId(),
                                   NULL));
@@ skipping 84 matching lines @@
   // after this line.
   next_mouse_move_.reset();
 
   StartHangMonitorTimeout(
       TimeDelta::FromMilliseconds(hung_renderer_delay_ms_));
 }
 
 void RenderWidgetHostImpl::ForwardTouchEventWithLatencyInfo(
     const WebKit::WebTouchEvent& touch_event,
     const ui::LatencyInfo& ui_latency) {
-  ui::LatencyInfo latency_info = NewInputLatencyInfo();
-  latency_info.MergeWith(ui_latency);
+  ui::LatencyInfo latency_info = CreateRWHLatencyInfoIfNotExist(&ui_latency);
   TouchEventWithLatencyInfo touch_with_latency(touch_event, latency_info);
   touch_event_queue_->QueueEvent(touch_with_latency);
 }
 
 void RenderWidgetHostImpl::AddKeyboardListener(KeyboardListener* listener) {
   keyboard_listeners_.AddObserver(listener);
 }
 
 void RenderWidgetHostImpl::RemoveKeyboardListener(
     KeyboardListener* listener) {
@@ skipping 1214 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_SCROLL_UPDATE_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.TouchToScrollUpdateSwap",
+        delta.InMicroseconds(),

[jbauman, 2013/07/12 00:50:39]

So this measures the latency from all the input events in a frame if that frame
includes at least one scroll update, right?

[Yufeng Shen (Slow to review), 2013/07/12 21:12:37]

solved by using SCROLL_UPDATE_ORIGINAL component.

+        0,
+        1000000,
+        100);
+    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);
+  }
 
   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