Add histograms for touchpad pinch zoom latency

In this patch, we make 3 changes to measure pinch zoom latency:
1. Separate touchpad pinch zoom latency info from wheel
2. Add histogram to measure pinch zoom latency from when receiving
   event from system to when sending event to render. This helps us
   understand the latency of waiting synthetic wheel event.
3. Add histogram to measure pinch zoom latency from when receiving
   event from system to when the resulting GPU frame swap completed.
   This helps us understand the latency of the end to end touchpad
   pinch.


Bug: 565980
Change-Id: I304675684746e6d8f6001937264afa0fc9037324
Reviewed-on: https://chromium-review.googlesource.com/1142447Reviewed-by: Sadrul Chowdhury <sadrul@chromium.org>
Reviewed-by: Daniel Cheng <dcheng@chromium.org>
Reviewed-by: Timothy Dresser <tdresser@chromium.org>
Reviewed-by: Steven Holte <holte@chromium.org>
Reviewed-by: Navid Zolghadr <nzolghadr@chromium.org>
Commit-Queue: Jianpeng Chao <chaopeng@chromium.org>
Cr-Commit-Position: refs/heads/master@{#579911}

content/browser/renderer_host/input/render_widget_host_latency_tracker_unittest.cc

@@ -1272,4 +1272,23 @@ TEST_F(RenderWidgetHostLatencyTrackerTest, WheelDuringMultiFingerTouch) {
               ElementsAre(Bucket(14, 1)));
 }
 
+TEST_F(RenderWidgetHostLatencyTrackerTest, TouchpadPinchEvents) {
+  ui::LatencyInfo latency;
+  latency.set_trace_id(kTraceEventId);
+  latency.set_source_event_type(ui::SourceEventType::TOUCHPAD);
+  latency.AddLatencyNumberWithTimestamp(
+      ui::INPUT_EVENT_LATENCY_ORIGINAL_COMPONENT,
+      base::TimeTicks() + base::TimeDelta::FromMilliseconds(1), 1);
+  latency.AddLatencyNumberWithTimestamp(
+      ui::INPUT_EVENT_LATENCY_BEGIN_RWH_COMPONENT,
+      base::TimeTicks() + base::TimeDelta::FromMilliseconds(3), 1);
+  AddFakeComponentsWithTimeStamp(
+      *tracker(), &latency,
+      base::TimeTicks() + base::TimeDelta::FromMilliseconds(5));
+  viz_tracker()->OnGpuSwapBuffersCompleted(latency);
+
+  EXPECT_TRUE(HistogramSizeEq("Event.Latency.EventToRender.TouchpadPinch", 1));
+  EXPECT_TRUE(HistogramSizeEq("Event.Latency.EndToEnd.TouchpadPinch", 1));
+}
+
 }  // namespace content

content/browser/renderer_host/render_widget_host_view_mac.mm

@@ -1183,7 +1183,7 @@ void RenderWidgetHostViewMac::SendGesturePinchEvent(WebGestureEvent* event) {
     DCHECK(event->SourceDevice() ==
            blink::WebGestureDevice::kWebGestureDeviceTouchpad);
     host()->delegate()->GetInputEventRouter()->RouteGestureEvent(
-        this, event, ui::LatencyInfo(ui::SourceEventType::WHEEL));
+        this, event, ui::LatencyInfo(ui::SourceEventType::TOUCHPAD));
     return;
   }
   host()->ForwardGestureEvent(*event);

tools/metrics/histograms/histograms.xml

@@ -24551,6 +24551,23 @@ uploading your change for review.
   </summary>
 </histogram>
 
+<histogram name="Event.Latency.EndToEnd.TouchpadPinch" units="microseconds">
+  <owner>input-dev@chromium.org</owner>
+  <summary>
+    Time between the OS receiving a touchpad pinch event and the resulting GPU
+    frame swap. If no swap was induced by the event, no recording is made.
+  </summary>
+</histogram>
+
+<histogram name="Event.Latency.EventToRender.TouchpadPinch"
+    units="microseconds">
+  <owner>input-dev@chromium.org</owner>
+  <summary>
+    Time between the OS receiving a touchpad pinch event and RenderWidgetHost
+    sending event to render.
+  </summary>
+</histogram>
+
 <histogram name="Event.Latency.HitTest" units="microseconds">
   <owner>dtapuska@chromium.org</owner>
   <summary>

ui/events/blink/web_input_event_traits.cc

@@ -251,6 +251,10 @@ LatencyInfo WebInputEventTraits::CreateLatencyInfoForWebGestureEvent(
   if (event.SourceDevice() ==
       blink::WebGestureDevice::kWebGestureDeviceTouchpad) {
     source_event_type = SourceEventType::WHEEL;
+    if (event.GetType() >= blink::WebInputEvent::kGesturePinchTypeFirst &&
+        event.GetType() <= blink::WebInputEvent::kGesturePinchTypeLast) {
+      source_event_type = SourceEventType::TOUCHPAD;
+    }
   } else if (event.SourceDevice() ==
              blink::WebGestureDevice::kWebGestureDeviceTouchscreen) {
     blink::WebGestureEvent::InertialPhaseState inertial_phase_state =

ui/events/event.cc

@@ -1411,6 +1411,11 @@ GestureEvent::GestureEvent(float x,
       details_(details),
       unique_touch_event_id_(unique_touch_event_id) {
   latency()->set_source_event_type(ui::SourceEventType::TOUCH);
+  // TODO(crbug.com/868056) Other touchpad gesture should report as TOUCHPAD.
+  if (IsPinchEvent() &&
+      details.device_type() == ui::GestureDeviceType::DEVICE_TOUCHPAD) {
+    latency()->set_source_event_type(ui::SourceEventType::TOUCHPAD);
+  }
 }
 
 GestureEvent::GestureEvent(const GestureEvent& other) = default;

ui/latency/latency_histogram_macros.h

@@ -21,6 +21,7 @@
       name, std::max(static_cast<int64_t>(0), (end - start).InMicroseconds()), \
       1, 5000000, 100);
 
+// Deprecated, use UMA_HISTOGRAM_INPUT_LATENCY_CUSTOM_MICROSECONDS instead.
 // Event latency that is mostly under 1 second. We should only use 100 buckets
 // when needed.
 #define UMA_HISTOGRAM_INPUT_LATENCY_HIGH_RESOLUTION_MICROSECONDS(name, start,  \
@@ -30,6 +31,15 @@
       name, std::max(static_cast<int64_t>(0), (end - start).InMicroseconds()), \
       1, 1000000, 100);
 
+// Event latency that is mostly under 1 second. We should only use 100 buckets
+// when needed. This drops reports on clients with low-resolution clocks.
+#define UMA_HISTOGRAM_INPUT_LATENCY_CUSTOM_MICROSECONDS(name, start, end) \
+  CONFIRM_EVENT_TIMES_EXIST(start, end)                                   \
+  base::TimeDelta frame_difference = end - start;                         \
+  UMA_HISTOGRAM_CUSTOM_MICROSECONDS_TIMES(                                \
+      name, frame_difference, base::TimeDelta::FromMicroseconds(1),       \
+      base::TimeDelta::FromMilliseconds(100), 100);
+
 #define UMA_HISTOGRAM_INPUT_LATENCY_MILLISECONDS(name, start, end)             \
   CONFIRM_EVENT_TIMES_EXIST(start, end)                                        \
   base::UmaHistogramCustomCounts(                                              \

ui/latency/latency_info.h

@@ -100,6 +100,8 @@ enum SourceEventType {
   TOUCH,
   INERTIAL,
   KEY_PRESS,
+  // TODO(crbug.com/868056) Touchpad scrolling latency report as WHEEL.
+  TOUCHPAD,
   FRAME,
   OTHER,
   SOURCE_EVENT_TYPE_LAST = OTHER,

ui/latency/latency_tracker.cc

@@ -35,6 +35,8 @@ std::string LatencySourceEventTypeToInputModalityString(
       return "Touch";
     case ui::SourceEventType::KEY_PRESS:
       return "KeyPress";
+    case ui::SourceEventType::TOUCHPAD:
+      return "Touchpad";
     default:
       return "";
   }
@@ -97,7 +99,8 @@ void LatencyTracker::OnGpuSwapBuffersCompleted(const LatencyInfo& latency) {
       source_event_type == ui::SourceEventType::MOUSE ||
       source_event_type == ui::SourceEventType::TOUCH ||
       source_event_type == ui::SourceEventType::INERTIAL ||
-      source_event_type == ui::SourceEventType::KEY_PRESS) {
+      source_event_type == ui::SourceEventType::KEY_PRESS ||
+      source_event_type == ui::SourceEventType::TOUCHPAD) {
     ComputeEndToEndLatencyHistograms(gpu_swap_begin_timestamp,
                                      gpu_swap_end_timestamp, latency);
   }
@@ -253,6 +256,17 @@ void LatencyTracker::ComputeEndToEndLatencyHistograms(
       UMA_HISTOGRAM_INPUT_LATENCY_HIGH_RESOLUTION_MICROSECONDS(
           "Event.Latency.EndToEnd.Mouse", original_timestamp,
           gpu_swap_begin_timestamp);
+    } else if (latency.source_event_type() == SourceEventType::TOUCHPAD) {
+      base::TimeTicks timestamp;
+      if (latency.FindLatency(ui::INPUT_EVENT_LATENCY_BEGIN_RWH_COMPONENT,
+                              &timestamp)) {
+        UMA_HISTOGRAM_INPUT_LATENCY_CUSTOM_MICROSECONDS(
+            "Event.Latency.EventToRender.TouchpadPinch", original_timestamp,
+            timestamp);
+      }
+      UMA_HISTOGRAM_INPUT_LATENCY_CUSTOM_MICROSECONDS(
+          "Event.Latency.EndToEnd.TouchpadPinch", original_timestamp,
+          gpu_swap_begin_timestamp);
     }
     return;
   } else {

ui/latency/mojo/latency_info.mojom

@@ -67,6 +67,7 @@ enum SourceEventType {
   TOUCH,
   INERTIAL,
   KEY_PRESS,
+  TOUCHPAD,
   FRAME,
   OTHER,
   SOURCE_EVENT_TYPE_LAST = OTHER,

ui/latency/mojo/latency_info_struct_traits.cc

@@ -24,6 +24,8 @@ ui::mojom::SourceEventType UISourceEventTypeToMojo(ui::SourceEventType type) {
       return ui::mojom::SourceEventType::INERTIAL;
     case ui::KEY_PRESS:
       return ui::mojom::SourceEventType::KEY_PRESS;
+    case ui::TOUCHPAD:
+      return ui::mojom::SourceEventType::TOUCHPAD;
     case ui::FRAME:
       return ui::mojom::SourceEventType::FRAME;
     case ui::OTHER:
@@ -47,6 +49,8 @@ ui::SourceEventType MojoSourceEventTypeToUI(ui::mojom::SourceEventType type) {
       return ui::INERTIAL;
     case ui::mojom::SourceEventType::KEY_PRESS:
       return ui::KEY_PRESS;
+    case ui::mojom::SourceEventType::TOUCHPAD:
+      return ui::TOUCHPAD;
     case ui::mojom::SourceEventType::FRAME:
       return ui::FRAME;
     case ui::mojom::SourceEventType::OTHER: