Add Keyboard Latency UMA Metrics.

content/browser/renderer_host/input/render_widget_host_latency_tracker_unittest.cc

 // Copyright 2014 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 "base/test/histogram_tester.h"
 #include "components/rappor/public/rappor_utils.h"
 #include "components/rappor/test_rappor_service.h"
 #include "content/browser/renderer_host/input/render_widget_host_latency_tracker.h"
 #include "content/common/input/synthetic_web_input_event_builders.h"
 #include "content/public/browser/native_web_keyboard_event.h"
@@ skipping 571 matching lines @@
                                INPUT_EVENT_ACK_STATE_NOT_CONSUMED);
     EXPECT_TRUE(scroll_latency.FindLatency(
         ui::INPUT_EVENT_LATENCY_TERMINATED_NO_SWAP_COMPONENT, 0, nullptr));
     EXPECT_TRUE(scroll_latency.terminated());
   }
 
   {
     auto wheel = SyntheticWebMouseWheelEventBuilder::Build(
         blink::WebMouseWheelEvent::kPhaseChanged);
     ui::LatencyInfo wheel_latency;
+    wheel_latency.set_source_event_type(ui::SourceEventType::WHEEL);
     AddFakeComponents(*tracker(), &wheel_latency);
     tracker()->OnInputEvent(wheel, &wheel_latency);
     tracker()->OnInputEventAck(wheel, &wheel_latency,
                                INPUT_EVENT_ACK_STATE_NOT_CONSUMED);
     EXPECT_TRUE(wheel_latency.FindLatency(
         ui::INPUT_EVENT_LATENCY_TERMINATED_NO_SWAP_COMPONENT, 0, nullptr));
     EXPECT_TRUE(wheel_latency.terminated());
   }
 
   {
     SyntheticWebTouchEvent touch;
     touch.PressPoint(0, 0);
     ui::LatencyInfo touch_latency;
+    touch_latency.set_source_event_type(ui::SourceEventType::TOUCH);
     AddFakeComponents(*tracker(), &touch_latency);
     tracker()->OnInputEvent(touch, &touch_latency);
     tracker()->OnInputEventAck(touch, &touch_latency,
                                INPUT_EVENT_ACK_STATE_NOT_CONSUMED);
     EXPECT_TRUE(touch_latency.FindLatency(
         ui::INPUT_EVENT_LATENCY_TERMINATED_NO_SWAP_COMPONENT, 0, nullptr));
     EXPECT_TRUE(touch_latency.terminated());
     tracker()->OnGpuSwapBuffersCompleted(touch_latency);
   }
 
   {
     auto mouse_move =
         SyntheticWebMouseEventBuilder::Build(blink::WebMouseEvent::kMouseMove);
     ui::LatencyInfo mouse_latency;
     AddFakeComponents(*tracker(), &mouse_latency);
     tracker()->OnInputEvent(mouse_move, &mouse_latency);
     tracker()->OnInputEventAck(mouse_move, &mouse_latency,
                                INPUT_EVENT_ACK_STATE_NOT_CONSUMED);
     EXPECT_TRUE(mouse_latency.FindLatency(
         ui::INPUT_EVENT_LATENCY_TERMINATED_NO_SWAP_COMPONENT, 0, nullptr));
     EXPECT_TRUE(mouse_latency.terminated());
   }
 
   {
     auto key_event =
         SyntheticWebKeyboardEventBuilder::Build(blink::WebKeyboardEvent::kChar);
     ui::LatencyInfo key_latency;
+    key_latency.set_source_event_type(ui::SourceEventType::KEY_PRESS);
     AddFakeComponents(*tracker(), &key_latency);
     tracker()->OnInputEvent(key_event, &key_latency);
     tracker()->OnInputEventAck(key_event, &key_latency,
                                INPUT_EVENT_ACK_STATE_NOT_CONSUMED);
     EXPECT_TRUE(key_latency.FindLatency(
         ui::INPUT_EVENT_LATENCY_TERMINATED_NO_SWAP_COMPONENT, 0, nullptr));
     EXPECT_TRUE(key_latency.terminated());
   }
 
   EXPECT_TRUE(HistogramSizeEq("Event.Latency.Browser.WheelUI", 1));
@@ skipping 76 matching lines @@
   int touchend_timestamps_ms[] = {3, 8, 12};
 
   for (InputEventAckState blocking :
        {INPUT_EVENT_ACK_STATE_NOT_CONSUMED, INPUT_EVENT_ACK_STATE_CONSUMED}) {
     SyntheticWebTouchEvent event;
     {
       // Touch start.
       event.PressPoint(1, 1);
 
       ui::LatencyInfo latency;
+      latency.set_source_event_type(ui::SourceEventType::TOUCH);
       tracker()->OnInputEvent(event, &latency);
 
       ui::LatencyInfo fake_latency;
+      fake_latency.set_source_event_type(ui::SourceEventType::TOUCH);
       fake_latency.AddLatencyNumberWithTimestamp(
           ui::INPUT_EVENT_LATENCY_BEGIN_RWH_COMPONENT,
           tracker()->latency_component_id(), 0,
           base::TimeTicks() +
               base::TimeDelta::FromMilliseconds(touchstart_timestamps_ms[0]),
           1);
 
       fake_latency.AddLatencyNumberWithTimestamp(
           ui::INPUT_EVENT_LATENCY_RENDERER_MAIN_COMPONENT, 0, 0,
           base::TimeTicks() +
@@ skipping 12 matching lines @@
           event.GetType(), tracker()->latency_component_id(), fake_latency,
           blocking);
 
       tracker()->OnInputEventAck(event, &latency,
                                  blocking);
     }
 
     {
       // Touch move.
       ui::LatencyInfo latency;
+      latency.set_source_event_type(ui::SourceEventType::TOUCH);
       event.MovePoint(0, 20, 20);
       tracker()->OnInputEvent(event, &latency);
 
       EXPECT_TRUE(latency.FindLatency(
           ui::INPUT_EVENT_LATENCY_ORIGINAL_COMPONENT, 0, nullptr));
       EXPECT_TRUE(
           latency.FindLatency(ui::INPUT_EVENT_LATENCY_BEGIN_RWH_COMPONENT,
                                    tracker()->latency_component_id(), nullptr));
 
       EXPECT_EQ(2U, latency.latency_components().size());
 
       ui::LatencyInfo fake_latency;
+      fake_latency.set_source_event_type(ui::SourceEventType::TOUCH);
       fake_latency.AddLatencyNumberWithTimestamp(
           ui::INPUT_EVENT_LATENCY_BEGIN_RWH_COMPONENT,
           tracker()->latency_component_id(), 0,
           base::TimeTicks() +
               base::TimeDelta::FromMilliseconds(touchmove_timestamps_ms[0]),
           1);
 
       fake_latency.AddLatencyNumberWithTimestamp(
           ui::INPUT_EVENT_LATENCY_RENDERER_MAIN_COMPONENT, 0, 0,
           base::TimeTicks() +
               base::TimeDelta::FromMilliseconds(touchmove_timestamps_ms[1]),
           1);
 
       fake_latency.AddLatencyNumberWithTimestamp(
           ui::INPUT_EVENT_LATENCY_ACK_RWH_COMPONENT, 0, 0,
           base::TimeTicks() +
               base::TimeDelta::FromMilliseconds(touchmove_timestamps_ms[2]),
           1);
 
       // Call ComputeInputLatencyHistograms directly to avoid OnInputEventAck
       // overwriting components.
       tracker()->ComputeInputLatencyHistograms(
           event.GetType(), tracker()->latency_component_id(), fake_latency,
           blocking);
     }
 
     {
       // Touch end.
       ui::LatencyInfo latency;
+      latency.set_source_event_type(ui::SourceEventType::TOUCH);
       event.ReleasePoint(0);
       tracker()->OnInputEvent(event, &latency);
 
       EXPECT_TRUE(latency.FindLatency(
           ui::INPUT_EVENT_LATENCY_ORIGINAL_COMPONENT, 0, nullptr));
       EXPECT_TRUE(
           latency.FindLatency(ui::INPUT_EVENT_LATENCY_BEGIN_RWH_COMPONENT,
                                    tracker()->latency_component_id(), nullptr));
 
       EXPECT_EQ(2U, latency.latency_components().size());
 
       ui::LatencyInfo fake_latency;
+      fake_latency.set_source_event_type(ui::SourceEventType::TOUCH);
       fake_latency.AddLatencyNumberWithTimestamp(
           ui::INPUT_EVENT_LATENCY_BEGIN_RWH_COMPONENT,
           tracker()->latency_component_id(), 0,
           base::TimeTicks() +
               base::TimeDelta::FromMilliseconds(touchend_timestamps_ms[0]),
           1);
 
       fake_latency.AddLatencyNumberWithTimestamp(
           ui::INPUT_EVENT_LATENCY_RENDERER_MAIN_COMPONENT, 0, 0,
           base::TimeTicks() +
@@ skipping 66 matching lines @@
   EXPECT_THAT(histogram_tester().GetAllSamples(
                   "Event.Latency.BlockingTime.TouchEndDefaultPrevented"),
               ElementsAre(Bucket(
                   touchend_timestamps_ms[2] - touchend_timestamps_ms[1], 1)));
   EXPECT_THAT(histogram_tester().GetAllSamples(
                   "Event.Latency.BlockingTime.TouchEndDefaultAllowed"),
               ElementsAre(Bucket(
                   touchend_timestamps_ms[2] - touchend_timestamps_ms[1], 1)));
 }
 
+TEST_F(RenderWidgetHostLatencyTrackerTest, KeyBlockingAndQueueingTime) {
+  // These numbers are sensitive to where the histogram buckets are.
+  int event_timestamps_ms[] = {11, 25, 35};
+
+  for (InputEventAckState blocking :
+       {INPUT_EVENT_ACK_STATE_NOT_CONSUMED, INPUT_EVENT_ACK_STATE_CONSUMED}) {
+    {
+      NativeWebKeyboardEvent event(blink::WebKeyboardEvent::kRawKeyDown,
+                                   blink::WebInputEvent::kNoModifiers,
+                                   base::TimeTicks::Now());
+      ui::LatencyInfo latency_info;
+      latency_info.set_source_event_type(ui::SourceEventType::KEY_PRESS);
+      tracker()->OnInputEvent(event, &latency_info);
+
+      ui::LatencyInfo fake_latency;
+      fake_latency.set_source_event_type(ui::SourceEventType::KEY_PRESS);
+      fake_latency.AddLatencyNumberWithTimestamp(
+          ui::INPUT_EVENT_LATENCY_BEGIN_RWH_COMPONENT,
+          tracker()->latency_component_id(), 0,
+          base::TimeTicks() +
+              base::TimeDelta::FromMilliseconds(event_timestamps_ms[0]),
+          1);
+
+      fake_latency.AddLatencyNumberWithTimestamp(
+          ui::INPUT_EVENT_LATENCY_RENDERER_MAIN_COMPONENT, 0, 0,
+          base::TimeTicks() +
+              base::TimeDelta::FromMilliseconds(event_timestamps_ms[1]),
+          1);
+
+      fake_latency.AddLatencyNumberWithTimestamp(
+          ui::INPUT_EVENT_LATENCY_ACK_RWH_COMPONENT, 0, 0,
+          base::TimeTicks() +
+              base::TimeDelta::FromMilliseconds(event_timestamps_ms[2]),
+          1);
+
+      // Call ComputeInputLatencyHistograms directly to avoid OnInputEventAck
+      // overwriting components.
+      tracker()->ComputeInputLatencyHistograms(
+          event.GetType(), tracker()->latency_component_id(), fake_latency,
+          blocking);
+
+      tracker()->OnInputEventAck(event, &latency_info, blocking);
+    }
+  }
+
+  EXPECT_THAT(
+      histogram_tester().GetAllSamples(
+          "Event.Latency.QueueingTime.KeyPressDefaultPrevented"),
+      ElementsAre(Bucket(event_timestamps_ms[1] - event_timestamps_ms[0], 1)));
+  EXPECT_THAT(
+      histogram_tester().GetAllSamples(
+          "Event.Latency.QueueingTime.KeyPressDefaultAllowed"),
+      ElementsAre(Bucket(event_timestamps_ms[1] - event_timestamps_ms[0], 1)));
+  EXPECT_THAT(
+      histogram_tester().GetAllSamples(
+          "Event.Latency.BlockingTime.KeyPressDefaultPrevented"),
+      ElementsAre(Bucket(event_timestamps_ms[2] - event_timestamps_ms[1], 1)));
+  EXPECT_THAT(
+      histogram_tester().GetAllSamples(
+          "Event.Latency.BlockingTime.KeyPressDefaultAllowed"),
+      ElementsAre(Bucket(event_timestamps_ms[2] - event_timestamps_ms[1], 1)));
+}
+
+TEST_F(RenderWidgetHostLatencyTrackerTest, KeyUILatency) {
+  // These numbers are sensitive to where the histogram buckets are.
+  int event_timestamps_microseconds[] = {100, 185};
+
+  NativeWebKeyboardEvent event(blink::WebKeyboardEvent::kChar,
+                               blink::WebInputEvent::kNoModifiers,
+                               base::TimeTicks::Now());
+  ui::LatencyInfo latency_info;
+  latency_info.set_source_event_type(ui::SourceEventType::KEY_PRESS);
+  latency_info.AddLatencyNumberWithTimestamp(
+      ui::INPUT_EVENT_LATENCY_UI_COMPONENT, 0, 0,
+      base::TimeTicks() +
+          base::TimeDelta::FromMicroseconds(event_timestamps_microseconds[0]),
+      1);
+
+  latency_info.AddLatencyNumberWithTimestamp(
+      ui::INPUT_EVENT_LATENCY_BEGIN_RWH_COMPONENT,
+      tracker()->latency_component_id(), 0,
+      base::TimeTicks() +
+          base::TimeDelta::FromMicroseconds(event_timestamps_microseconds[1]),
+      1);
+
+  tracker()->OnInputEvent(event, &latency_info);
+  tracker()->OnInputEventAck(event, &latency_info,
+                             InputEventAckState::INPUT_EVENT_ACK_STATE_UNKNOWN);
+  EXPECT_THAT(
+      histogram_tester().GetAllSamples("Event.Latency.Browser.KeyPressUI"),
+      ElementsAre(Bucket(
+          event_timestamps_microseconds[1] - event_timestamps_microseconds[0],
+          1)));
+}
+
+TEST_F(RenderWidgetHostLatencyTrackerTest, KeyAckedLatency) {
+  // These numbers are sensitive to where the histogram buckets are.
+  int event_timestamps_microseconds[] = {11, 24};
+
+  NativeWebKeyboardEvent event(blink::WebKeyboardEvent::kRawKeyDown,
+                               blink::WebInputEvent::kNoModifiers,
+                               base::TimeTicks::Now());
+  ui::LatencyInfo latency_info;
+  latency_info.set_source_event_type(ui::SourceEventType::KEY_PRESS);
+
+  latency_info.AddLatencyNumberWithTimestamp(
+      ui::INPUT_EVENT_LATENCY_BEGIN_RWH_COMPONENT,
+      tracker()->latency_component_id(), 0,
+      base::TimeTicks() +
+          base::TimeDelta::FromMicroseconds(event_timestamps_microseconds[0]),
+      1);
+
+  latency_info.AddLatencyNumberWithTimestamp(
+      ui::INPUT_EVENT_LATENCY_ACK_RWH_COMPONENT, 0, 0,
+      base::TimeTicks() +
+          base::TimeDelta::FromMicroseconds(event_timestamps_microseconds[1]),
+      1);
+
+  tracker()->OnInputEvent(event, &latency_info);
+  // Call ComputeInputLatencyHistograms directly to avoid OnInputEventAck
+  // overwriting components.
+  tracker()->ComputeInputLatencyHistograms(
+      event.GetType(), tracker()->latency_component_id(), latency_info,
+      InputEventAckState::INPUT_EVENT_ACK_STATE_UNKNOWN);
+
+  EXPECT_THAT(
+      histogram_tester().GetAllSamples("Event.Latency.Browser.KeyPressAcked"),
+      ElementsAre(Bucket(
+          event_timestamps_microseconds[1] - event_timestamps_microseconds[0],
+          1)));
+}
+
+TEST_F(RenderWidgetHostLatencyTrackerTest, KeyEndToEndLatency) {
+  // These numbers are sensitive to where the histogram buckets are.
+  int event_timestamps_microseconds[] = {11, 24};
+
+  ui::LatencyInfo latency_info;
+  latency_info.set_source_event_type(ui::SourceEventType::KEY_PRESS);
+  latency_info.AddLatencyNumberWithTimestamp(
+      ui::INPUT_EVENT_LATENCY_ORIGINAL_COMPONENT, 0, 0,
+      base::TimeTicks() +
+          base::TimeDelta::FromMicroseconds(event_timestamps_microseconds[0]),
+      1);
+
+  latency_info.AddLatencyNumberWithTimestamp(
+      ui::INPUT_EVENT_LATENCY_BEGIN_RWH_COMPONENT,
+      tracker()->latency_component_id(), 0,
+      base::TimeTicks() +
+          base::TimeDelta::FromMicroseconds(event_timestamps_microseconds[0]),
+      1);
+
+  latency_info.AddLatencyNumberWithTimestamp(
+      ui::INPUT_EVENT_GPU_SWAP_BUFFER_COMPONENT, 0, 0,
+      base::TimeTicks() +
+          base::TimeDelta::FromMicroseconds(event_timestamps_microseconds[1]),
+      1);
+
+  latency_info.AddLatencyNumberWithTimestamp(
+      ui::INPUT_EVENT_LATENCY_TERMINATED_FRAME_SWAP_COMPONENT, 0, 0,
+      base::TimeTicks() +
+          base::TimeDelta::FromMicroseconds(event_timestamps_microseconds[1]),
+      1);
+
+  tracker()->OnGpuSwapBuffersCompleted(latency_info);
+
+  EXPECT_THAT(
+      histogram_tester().GetAllSamples("Event.Latency.EndToEnd.KeyPress"),
+      ElementsAre(Bucket(
+          event_timestamps_microseconds[1] - event_timestamps_microseconds[0],
+          1)));
+}
+
 // Event.Latency.(Queueing|Blocking)Time.* histograms shouldn't be reported for
 // multi-finger touch.
 TEST_F(RenderWidgetHostLatencyTrackerTest,
        MultiFingerTouchIgnoredForQueueingAndBlockingTimeMetrics) {
   SyntheticWebTouchEvent event;
   InputEventAckState ack_state = INPUT_EVENT_ACK_STATE_NOT_CONSUMED;
 
   {
     // First touch start.
     ui::LatencyInfo latency;
@@ skipping 47 matching lines @@
 // Some touch input histograms aren't reported for multi-finger touch. Other
 // input modalities shouldn't be impacted by there being an active multi-finger
 // touch gesture.
 TEST_F(RenderWidgetHostLatencyTrackerTest, WheelDuringMultiFingerTouch) {
   SyntheticWebTouchEvent touch_event;
   InputEventAckState ack_state = INPUT_EVENT_ACK_STATE_NOT_CONSUMED;
 
   {
     // First touch start.
     ui::LatencyInfo latency;
+    latency.set_source_event_type(ui::SourceEventType::TOUCH);
     touch_event.PressPoint(1, 1);
     tracker()->OnInputEvent(touch_event, &latency);
     tracker()->OnInputEventAck(touch_event, &latency, ack_state);
   }
 
   {
     // Second touch start.
     ui::LatencyInfo latency;
+    latency.set_source_event_type(ui::SourceEventType::TOUCH);
     touch_event.PressPoint(1, 1);
     tracker()->OnInputEvent(touch_event, &latency);
     tracker()->OnInputEventAck(touch_event, &latency, ack_state);
   }
 
   {
     // Wheel event.
     ui::LatencyInfo latency;
+    latency.set_source_event_type(ui::SourceEventType::WHEEL);
     // These numbers are sensitive to where the histogram buckets are.
     int timestamps_ms[] = {11, 25, 35};
     auto wheel_event = SyntheticWebMouseWheelEventBuilder::Build(
         blink::WebMouseWheelEvent::kPhaseChanged);
     tracker()->OnInputEvent(touch_event, &latency);
 
     ui::LatencyInfo fake_latency;
+    fake_latency.set_source_event_type(ui::SourceEventType::TOUCH);
     fake_latency.AddLatencyNumberWithTimestamp(
         ui::INPUT_EVENT_LATENCY_BEGIN_RWH_COMPONENT,
         tracker()->latency_component_id(), 0,
         base::TimeTicks() + base::TimeDelta::FromMilliseconds(timestamps_ms[0]),
         1);
 
     fake_latency.AddLatencyNumberWithTimestamp(
         ui::INPUT_EVENT_LATENCY_RENDERER_MAIN_COMPONENT, 0, 0,
         base::TimeTicks() + base::TimeDelta::FromMilliseconds(timestamps_ms[1]),
         1);
@@ skipping 11 matching lines @@
 
     tracker()->OnInputEventAck(wheel_event, &latency, ack_state);
   }
 
   EXPECT_THAT(histogram_tester().GetAllSamples(
                   "Event.Latency.QueueingTime.MouseWheelDefaultAllowed"),
               ElementsAre(Bucket(14, 1)));
 }
 
 }  // namespace content