Add TimeToScrollUpdateSwapBegin2 to UKM

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 "content/browser/renderer_host/input/render_widget_host_latency_tracker.h"
+#include "base/metrics/metrics_hashes.h"
 #include "base/test/histogram_tester.h"
+#include "components/metrics/proto/ukm/entry.pb.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 "components/ukm/test_ukm_recorder.h"
+#include "components/ukm/ukm_source.h"
 #include "content/common/input/synthetic_web_input_event_builders.h"
 #include "content/public/browser/native_web_keyboard_event.h"
 #include "content/test/test_content_browser_client.h"
 #include "content/test/test_render_view_host.h"
 #include "content/test/test_web_contents.h"
 #include "testing/gmock/include/gmock/gmock.h"
 #include "testing/gtest/include/gtest/gtest.h"
 
 using base::Bucket;
 using blink::WebInputEvent;
 using testing::ElementsAre;
 
 namespace content {
 namespace {
 
+const char kUrl[] = "http://www.foo.bar.com/subpage/1";
+
 void AddFakeComponentsWithTimeStamp(
     const RenderWidgetHostLatencyTracker& tracker,
     ui::LatencyInfo* latency,
     base::TimeTicks time_stamp) {
   latency->AddLatencyNumberWithTimestamp(ui::INPUT_EVENT_LATENCY_UI_COMPONENT,
                                          0, 0, time_stamp, 1);
   latency->AddLatencyNumberWithTimestamp(
       ui::INPUT_EVENT_LATENCY_TERMINATED_FRAME_SWAP_COMPONENT, 0, 0, time_stamp,
       1);
   latency->AddLatencyNumberWithTimestamp(
@@ skipping 36 matching lines @@
   ~RenderWidgetHostLatencyTrackerTestBrowserClient() override {}
 
   rappor::RapporService* GetRapporService() override {
     return &rappor_service_;
   }
 
   rappor::TestRapporServiceImpl* getTestRapporService() {
     return &rappor_service_;
   }
 
+  ukm::UkmRecorder* GetUkmRecorder() override { return &test_ukm_recorder_; }
+
+  ukm::TestUkmRecorder* GetTestUkmRecorder() { return &test_ukm_recorder_; }
+
  private:
   rappor::TestRapporServiceImpl rappor_service_;
+  ukm::TestUkmRecorder test_ukm_recorder_;
   DISALLOW_COPY_AND_ASSIGN(RenderWidgetHostLatencyTrackerTestBrowserClient);
 };
 
 class RenderWidgetHostLatencyTrackerTest
     : public RenderViewHostImplTestHarness {
  public:
   RenderWidgetHostLatencyTrackerTest() : old_browser_client_(NULL) {
     tracker_.Initialize(kTestRoutingId, kTestProcessId);
     ResetHistograms();
   }
@@ skipping 34 matching lines @@
       return ::testing::AssertionSuccess();
     } else {
       if (!sample_obj)
         return ::testing::AssertionSuccess();
       else
         return ::testing::AssertionFailure() << rappor_name
                                              << " rappor sample should be null";
     }
   }
 
+  ::testing::AssertionResult UkmReportAssert(const char* event_name) {
+    const ukm::TestUkmRecorder* ukm_recoder =
+        test_browser_client_.GetTestUkmRecorder();
+    size_t expected_metrics_index = 0;

[tdresser, 2017/05/30 16:52:07]

It isn't clear from the name what this is.

[Navid Zolghadr, 2017/05/31 20:37:15]

renamed.

+    for (size_t i = 0; i < ukm_recoder->entries_count(); ++i) {

[tdresser, 2017/05/30 16:52:07]

Could this be a range based for?

[Navid Zolghadr, 2017/05/31 20:37:15]

It seems that ukm_recorder is not (and does not return) an iterable object.

[tdresser, 2017/06/01 12:44:44]

Acknowledged.

+      const ukm::mojom::UkmEntry* entry = ukm_recoder->GetEntry(i);
+      if (entry->event_hash != base::HashMetricName(event_name))
+        continue;
+
+      const ukm::UkmSource* source =
+          ukm_recoder->GetSourceForSourceId(entry->source_id);
+      if (!source)
+        return ::testing::AssertionFailure() << "Source should not be null";
+
+      if (expected_metrics_index >= 1)
+        break;
+
+      if (GURL(kUrl) != source->url())
+        return ::testing::AssertionFailure() << "Incorrect URL is reported.";
+
+      expected_metrics_index++;
+      if (entry->metrics.size() != 1)
+        return ::testing::AssertionFailure()
+               << event_name << " entry expected only 1 metric but got "
+               << entry->metrics.size();
+
+      if (entry->metrics[0]->metric_hash != base::HashMetricName("Latency"))
+        return ::testing::AssertionFailure()
+               << "Expected a metric named 'Latency'";
+    }
+    if (expected_metrics_index != 1)
+      return ::testing::AssertionFailure()
+             << event_name << " expected " << 1 << " entries but got "
+             << expected_metrics_index;
+    return ::testing::AssertionSuccess();
+  }
+
   ::testing::AssertionResult HistogramSizeEq(const char* histogram_name,
                                              int size) {
     uint64_t histogram_size =
         histogram_tester_->GetAllSamples(histogram_name).size();
     if (static_cast<uint64_t>(size) == histogram_size) {
       return ::testing::AssertionSuccess();
     } else {
       return ::testing::AssertionFailure() << histogram_name << " expected "
                                            << size << " entries, but had "
                                            << histogram_size;
     }
   }
 
   RenderWidgetHostLatencyTracker* tracker() { return &tracker_; }
   void ResetHistograms() {
     histogram_tester_.reset(new base::HistogramTester());
+    test_browser_client_.GetTestUkmRecorder()->Purge();
   }
 
   const base::HistogramTester& histogram_tester() {
     return *histogram_tester_;
   }
 
   void SetUp() override {
     RenderViewHostImplTestHarness::SetUp();
     old_browser_client_ = SetBrowserClientForTesting(&test_browser_client_);
     tracker_.SetDelegate(contents());
   }
 
   void TearDown() override {
     SetBrowserClientForTesting(old_browser_client_);
     RenderViewHostImplTestHarness::TearDown();
   }
 
  protected:
   DISALLOW_COPY_AND_ASSIGN(RenderWidgetHostLatencyTrackerTest);
   const int kTestRoutingId = 3;
   const int kTestProcessId = 1;
   std::unique_ptr<base::HistogramTester> histogram_tester_;
   RenderWidgetHostLatencyTracker tracker_;
   RenderWidgetHostLatencyTrackerTestBrowserClient test_browser_client_;
   ContentBrowserClient* old_browser_client_;
 };
 
 TEST_F(RenderWidgetHostLatencyTrackerTest, TestWheelToFirstScrollHistograms) {
-  const GURL url("http://www.foo.bar.com/subpage/1");
+  const GURL url(kUrl);
   contents()->NavigateAndCommit(url);
   for (bool rendering_on_main : {false, true}) {
     ResetHistograms();
     {
       auto wheel = SyntheticWebMouseWheelEventBuilder::Build(
           blink::WebMouseWheelEvent::kPhaseChanged);
       base::TimeTicks now = base::TimeTicks::Now();
       wheel.SetTimeStampSeconds((now - base::TimeTicks()).InSecondsF());
       ui::LatencyInfo wheel_latency(ui::SourceEventType::WHEEL);
       wheel_latency.AddLatencyNumberWithTimestamp(
@@ skipping 67 matching lines @@
       EXPECT_TRUE(HistogramSizeEq(
           "Event.Latency.ScrollUpdate.Wheel.HandledToRendererSwap2_Impl", 0));
       EXPECT_TRUE(HistogramSizeEq(
           "Event.Latency.ScrollUpdate.Wheel.RendererSwapToBrowserNotified2",
           0));
       EXPECT_TRUE(HistogramSizeEq(
           "Event.Latency.ScrollUpdate.Wheel.BrowserNotifiedToBeforeGpuSwap2",
           0));
       EXPECT_TRUE(
           HistogramSizeEq("Event.Latency.ScrollUpdate.Wheel.GpuSwap2", 0));
+
+      ukm::TestUkmRecorder* test_ukm_recorder =
+          test_browser_client_.GetTestUkmRecorder();
+      EXPECT_EQ(0U, test_ukm_recorder->sources_count());
+      EXPECT_EQ(0U, test_ukm_recorder->entries_count());
     }
   }
 }
 
 TEST_F(RenderWidgetHostLatencyTrackerTest, TestWheelToScrollHistograms) {
   for (bool rendering_on_main : {false, true}) {
     ResetHistograms();
     {
       auto wheel = SyntheticWebMouseWheelEventBuilder::Build(
           blink::WebMouseWheelEvent::kPhaseChanged);
@@ skipping 58 matching lines @@
       EXPECT_TRUE(HistogramSizeEq(
           "Event.Latency.ScrollUpdate.Wheel.BrowserNotifiedToBeforeGpuSwap2",
           1));
       EXPECT_TRUE(
           HistogramSizeEq("Event.Latency.ScrollUpdate.Wheel.GpuSwap2", 1));
     }
   }
 }
 
 TEST_F(RenderWidgetHostLatencyTrackerTest, TestTouchToFirstScrollHistograms) {
-  const GURL url("http://www.foo.bar.com/subpage/1");
+  const GURL url(kUrl);
   contents()->NavigateAndCommit(url);
   for (bool rendering_on_main : {false, true}) {
     ResetHistograms();
     {
       auto scroll = SyntheticWebGestureEventBuilder::BuildScrollUpdate(
           5.f, -5.f, 0, blink::kWebGestureDeviceTouchscreen);
       base::TimeTicks now = base::TimeTicks::Now();
       scroll.SetTimeStampSeconds((now - base::TimeTicks()).InSecondsF());
       ui::LatencyInfo scroll_latency;
       scroll_latency.AddLatencyNumberWithTimestamp(
@@ skipping 91 matching lines @@
     EXPECT_TRUE(HistogramSizeEq(
         "Event.Latency.ScrollUpdate.Touch.HandledToRendererSwap2_Main", 0));
     EXPECT_TRUE(HistogramSizeEq(
         "Event.Latency.ScrollUpdate.Touch.HandledToRendererSwap2_Impl", 0));
     EXPECT_TRUE(HistogramSizeEq(
         "Event.Latency.ScrollUpdate.Touch.RendererSwapToBrowserNotified2", 0));
     EXPECT_TRUE(HistogramSizeEq(
         "Event.Latency.ScrollUpdate.Touch.BrowserNotifiedToBeforeGpuSwap2", 0));
     EXPECT_TRUE(
         HistogramSizeEq("Event.Latency.ScrollUpdate.Touch.GpuSwap2", 0));
+
+    ukm::TestUkmRecorder* test_ukm_recorder =
+        test_browser_client_.GetTestUkmRecorder();
+    EXPECT_EQ(0U, test_ukm_recorder->sources_count());
+    EXPECT_EQ(0U, test_ukm_recorder->entries_count());
   }
 }
 
 TEST_F(RenderWidgetHostLatencyTrackerTest, TestTouchToScrollHistograms) {
-  const GURL url("http://www.foo.bar.com/subpage/1");
+  const GURL url(kUrl);
   contents()->NavigateAndCommit(url);
   for (bool rendering_on_main : {false, true}) {
     ResetHistograms();
     EXPECT_EQ(0,
               test_browser_client_.getTestRapporService()->GetReportsCount());
     {
       auto scroll = SyntheticWebGestureEventBuilder::BuildScrollUpdate(
           5.f, -5.f, 0, blink::kWebGestureDeviceTouchscreen);
       base::TimeTicks now = base::TimeTicks::Now();
       scroll.SetTimeStampSeconds((now - base::TimeTicks()).InSecondsF());
@@ skipping 28 matching lines @@
       EXPECT_TRUE(touch_latency.FindLatency(
           ui::INPUT_EVENT_LATENCY_BEGIN_RWH_COMPONENT,
           tracker()->latency_component_id(), nullptr));
       EXPECT_TRUE(touch_latency.FindLatency(
           ui::INPUT_EVENT_LATENCY_ORIGINAL_COMPONENT, 0, nullptr));
       tracker()->OnInputEventAck(touch, &touch_latency,
                                  INPUT_EVENT_ACK_STATE_NOT_CONSUMED);
       tracker()->OnGpuSwapBuffersCompleted(touch_latency);
     }
 
+    // UKM metrics.
+    EXPECT_TRUE(UkmReportAssert(
+        "Event.Latency.ScrollUpdate.Touch.TimeToScrollUpdateSwapBegin2"));
+
     // Rappor metrics.
     EXPECT_TRUE(
         RapporSampleAssert("Event.Latency.ScrollUpdate.Touch."
                            "TimeToScrollUpdateSwapBegin2",
                            2));
     EXPECT_TRUE(
         RapporSampleAssert("Event.Latency.ScrollBegin.Touch."
                            "TimeToScrollUpdateSwapBegin2",
                            0));
     EXPECT_TRUE(
@@ skipping 37 matching lines @@
         rendering_on_main ? 1 : 0));
     EXPECT_TRUE(HistogramSizeEq(
         "Event.Latency.ScrollUpdate.Touch.HandledToRendererSwap2_Impl",
         rendering_on_main ? 0 : 1));
     EXPECT_TRUE(HistogramSizeEq(
         "Event.Latency.ScrollUpdate.Touch.RendererSwapToBrowserNotified2", 1));
     EXPECT_TRUE(HistogramSizeEq(
         "Event.Latency.ScrollUpdate.Touch.BrowserNotifiedToBeforeGpuSwap2", 1));
     EXPECT_TRUE(
         HistogramSizeEq("Event.Latency.ScrollUpdate.Touch.GpuSwap2", 1));
+
+    ukm::TestUkmRecorder* test_ukm_recorder =
+        test_browser_client_.GetTestUkmRecorder();
+    EXPECT_EQ(1U, test_ukm_recorder->sources_count());
+    EXPECT_EQ(1U, test_ukm_recorder->entries_count());

[tdresser, 2017/05/30 16:52:07]

Should we be using UkmReportAssert here?

[Navid Zolghadr, 2017/05/31 20:37:15]

It is used earlier in the function. I got rid of this to make it more clear as
I'm going to add the test of the metrics right after this and they will verify
anything that will be reported anyway.

   }
 }
 
 TEST_F(RenderWidgetHostLatencyTrackerTest,
        LatencyTerminatedOnAckIfRenderingNotScheduled) {
   {
     auto scroll = SyntheticWebGestureEventBuilder::BuildScrollBegin(
         5.f, -5.f, blink::kWebGestureDeviceTouchscreen);
     ui::LatencyInfo scroll_latency;
     AddFakeComponents(*tracker(), &scroll_latency);
@@ skipping 620 matching lines @@
 
     tracker()->OnInputEventAck(wheel_event, &latency, ack_state);
   }
 
   EXPECT_THAT(histogram_tester().GetAllSamples(
                   "Event.Latency.QueueingTime.MouseWheelDefaultAllowed"),
               ElementsAre(Bucket(14, 1)));
 }
 
 }  // namespace content