| // Copyright 2020 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 "cc/metrics/average_lag_tracking_manager.h" |
| |
| #include <algorithm> |
| #include <memory> |
| |
| #include "base/test/metrics/histogram_tester.h" |
| #include "components/viz/common/frame_timing_details.h" |
| #include "testing/gmock/include/gmock/gmock.h" |
| #include "testing/gtest/include/gtest/gtest.h" |
| #include "ui/latency/latency_info.h" |
| |
| namespace cc { |
| namespace { |
| |
| using base::Bucket; |
| using testing::ElementsAre; |
| |
| // Helper for TimeTicks usage |
| base::TimeTicks MillisecondsToTimeTicks(float t_ms) { |
| return base::TimeTicks() + base::TimeDelta::FromMilliseconds(t_ms); |
| } |
| |
| // Helper for FrameTimingDetails usage in DidPresentCompositorFrame |
| viz::FrameTimingDetails PrepareFrameDetails(base::TimeTicks swap_time) { |
| gfx::SwapTimings timings; |
| timings.swap_start = swap_time; |
| viz::FrameTimingDetails details; |
| details.swap_timings = timings; |
| return details; |
| } |
| |
| class AverageLagTrackingManagerTest : public testing::Test { |
| protected: |
| AverageLagTrackingManagerTest() = default; |
| |
| void SetUp() override { ResetHistograms(); } |
| |
| void ResetHistograms() { |
| histogram_tester_ = std::make_unique<base::HistogramTester>(); |
| } |
| |
| // Creates a scroll event each |scroll_rate| (in ms) of |scroll_delta| px. |
| // Collect events at the expected |frame_times|. |
| void SimulateConstantScroll(const std::vector<unsigned int>& frame_times, |
| float scroll_delta, |
| unsigned int scroll_rate) { |
| if (frame_times.size() == 0 || frame_times[0] < scroll_rate) |
| return; |
| |
| // Creates 1st frame with scroll begin |
| std::vector<ui::LatencyInfo> events(frame_times[0] / scroll_rate); |
| base::TimeTicks event_time = MillisecondsToTimeTicks(scroll_rate); |
| events[0] = PrepareScrollEvent(AverageLagTracker::EventType::ScrollBegin, |
| event_time, 0, scroll_delta); |
| for (size_t i = 1; i < events.size(); i++) { |
| event_time += base::TimeDelta::FromMilliseconds(scroll_rate); |
| events[i] = PrepareScrollEvent(AverageLagTracker::EventType::ScrollUpdate, |
| event_time, i, scroll_delta); |
| } |
| average_lag_tracking_manager_.CollectScrollEventsFromFrame(0, events); |
| |
| // Creates remaining frames |
| for (size_t frame = 1; frame < frame_times.size(); frame++) { |
| unsigned int time_delta = frame_times[frame] - frame_times[frame - 1]; |
| events = std::vector<ui::LatencyInfo>(time_delta / scroll_rate); |
| for (size_t i = 0; i < events.size(); i++) { |
| event_time += base::TimeDelta::FromMilliseconds(scroll_rate); |
| events[i] = |
| PrepareScrollEvent(AverageLagTracker::EventType::ScrollUpdate, |
| event_time, i, scroll_delta); |
| } |
| average_lag_tracking_manager_.CollectScrollEventsFromFrame(frame, events); |
| } |
| } |
| |
| // Prepares a ui::LatencyInfo object for a ScrollEvent |
| ui::LatencyInfo PrepareScrollEvent(AverageLagTracker::EventType event_type, |
| base::TimeTicks event_time, |
| int trace_id, |
| float delta, |
| float predicted_delta = 0) { |
| ui::LatencyInfo info; |
| info.set_trace_id(trace_id); |
| info.set_source_event_type(ui::SourceEventType::TOUCH); |
| |
| info.AddLatencyNumberWithTimestamp( |
| event_type == AverageLagTracker::EventType::ScrollBegin |
| ? ui::INPUT_EVENT_LATENCY_FIRST_SCROLL_UPDATE_ORIGINAL_COMPONENT |
| : ui::INPUT_EVENT_LATENCY_SCROLL_UPDATE_ORIGINAL_COMPONENT, |
| event_time); |
| |
| info.AddLatencyNumberWithTimestamp( |
| ui::INPUT_EVENT_LATENCY_SCROLL_UPDATE_LAST_EVENT_COMPONENT, event_time); |
| |
| info.set_scroll_update_delta(delta); |
| info.set_predicted_scroll_update_delta( |
| predicted_delta != 0 ? predicted_delta : delta); |
| |
| return info; |
| } |
| |
| AverageLagTrackingManager average_lag_tracking_manager_; |
| std::unique_ptr<base::HistogramTester> histogram_tester_; |
| }; |
| |
| // Simulate a simple situation that events at every 10ms and start at t=15ms, |
| // frame swaps at every 10ms too and start at t=20ms and test we record one |
| // UMA for ScrollUpdate in one second. Tests using CollectScrollEventAtFrame |
| // (1 event per collection) |
| TEST_F(AverageLagTrackingManagerTest, OneSecondInterval) { |
| base::TimeTicks event_time = MillisecondsToTimeTicks(5); |
| base::TimeTicks frame_time = MillisecondsToTimeTicks(10); |
| float scroll_delta = 10; |
| int frame_id = 1; |
| |
| // ScrollBegin |
| event_time += base::TimeDelta::FromMilliseconds(10); // 15ms |
| frame_time += base::TimeDelta::FromMilliseconds(10); // 20ms |
| ui::LatencyInfo evt = PrepareScrollEvent( |
| AverageLagTracker::EventType::ScrollBegin, event_time, 1, scroll_delta); |
| average_lag_tracking_manager_.CollectScrollEventsFromFrame( |
| frame_id, std::vector<ui::LatencyInfo>{evt}); |
| average_lag_tracking_manager_.DidPresentCompositorFrame( |
| frame_id, PrepareFrameDetails(frame_time)); |
| |
| // Send 101 ScrollUpdate events to verify that there is 1 AverageLag record |
| // per 1 second. |
| const int kUpdates = 101; |
| for (int i = 0; i < kUpdates; i++) { |
| event_time += base::TimeDelta::FromMilliseconds(10); |
| frame_time += base::TimeDelta::FromMilliseconds(10); |
| // First 50 has positive delta, others negative delta. |
| const int sign = (i < kUpdates / 2) ? 1 : -1; |
| |
| evt = PrepareScrollEvent(AverageLagTracker::EventType::ScrollUpdate, |
| event_time, 1, sign * scroll_delta); |
| average_lag_tracking_manager_.CollectScrollEventsFromFrame( |
| frame_id, std::vector<ui::LatencyInfo>{evt}); |
| average_lag_tracking_manager_.DidPresentCompositorFrame( |
| frame_id, PrepareFrameDetails(frame_time)); |
| } |
| |
| // ScrollBegin report_time is at 20ms, so the next ScrollUpdate report_time is |
| // at 1020ms. The last event_time that finish this report should be later than |
| // 1020ms. |
| EXPECT_EQ(event_time, MillisecondsToTimeTicks(1025)); |
| EXPECT_EQ(frame_time, MillisecondsToTimeTicks(1030)); |
| |
| // ScrollBegin AverageLag are the area between the event original component |
| // (time=15ms, delta=10px) to the frame swap time (time=20ms, expect finger |
| // position at delta=15px). The AverageLag scaled to 1 second is |
| // (0.5*(10px+15px)*5ms)/5ms = 12.5px. |
| EXPECT_THAT(histogram_tester_->GetAllSamples( |
| "Event.Latency.ScrollBegin.Touch.AverageLag"), |
| ElementsAre(Bucket(12, 1))); |
| // This ScrollUpdate AverageLag are calculated as the finger uniformly scroll |
| // 10px each frame. For scroll up/down frame, the Lag at the last frame swap |
| // is 5px, and Lag at this frame swap is 15px. For the one changing direction, |
| // the Lag is from 5 to 10 and down to 5 again. So total LagArea is 99 * 100, |
| // plus 75. the AverageLag in 1 second is 9.975px. |
| EXPECT_THAT(histogram_tester_->GetAllSamples( |
| "Event.Latency.ScrollUpdate.Touch.AverageLag"), |
| ElementsAre(Bucket(9, 1))); |
| EXPECT_THAT( |
| histogram_tester_->GetAllSamples( |
| "Event.Latency.ScrollUpdate.Touch.AverageLag.PredictionPositive"), |
| ElementsAre(Bucket(0, 1))); |
| histogram_tester_->ExpectTotalCount( |
| "Event.Latency.ScrollUpdate.Touch.AverageLag.PredictionNegative", 0); |
| ResetHistograms(); |
| |
| // Send another ScrollBegin to end the unfinished ScrollUpdate report. |
| event_time += base::TimeDelta::FromMilliseconds(10); |
| frame_time += base::TimeDelta::FromMilliseconds(10); |
| evt = PrepareScrollEvent(AverageLagTracker::EventType::ScrollBegin, |
| event_time, 1, scroll_delta); |
| average_lag_tracking_manager_.CollectScrollEventsFromFrame( |
| frame_id, std::vector<ui::LatencyInfo>{evt}); |
| average_lag_tracking_manager_.DidPresentCompositorFrame( |
| frame_id, PrepareFrameDetails(frame_time)); |
| |
| // The last ScrollUpdate's lag is 8.75px and truncated to 8. |
| EXPECT_THAT(histogram_tester_->GetAllSamples( |
| "Event.Latency.ScrollUpdate.Touch.AverageLag"), |
| ElementsAre(Bucket(8, 1))); |
| EXPECT_THAT( |
| histogram_tester_->GetAllSamples( |
| "Event.Latency.ScrollUpdate.Touch.AverageLag.PredictionPositive"), |
| ElementsAre(Bucket(0, 1))); |
| histogram_tester_->ExpectTotalCount( |
| "Event.Latency.ScrollUpdate.Touch.AverageLag.PredictionNegative", 0); |
| } |
| |
| // This test creates 3 frames in order to check the submission of ScrollBegin |
| // and ScrollUpdate events sent using CollectScrollEventsAtFrame (multiple |
| // events per collection) |
| TEST_F(AverageLagTrackingManagerTest, MultipleEventsInSameFrame) { |
| std::vector<unsigned int> frame_times = {400, 1400, 1600}; |
| SimulateConstantScroll(frame_times, 10, 100); |
| for (size_t frame = 0; frame < frame_times.size(); frame++) { |
| average_lag_tracking_manager_.DidPresentCompositorFrame( |
| frame, |
| PrepareFrameDetails(MillisecondsToTimeTicks(frame_times[frame]))); |
| } |
| |
| // As the first frame is the ScrollBegin frame, the average lag is |
| // 0.5*(10 + 40) * 30 / 30 = 25. But UmaHistogramCounts1000's binning will |
| // round it to 23. |
| EXPECT_THAT(histogram_tester_->GetAllSamples( |
| "Event.Latency.ScrollBegin.Touch.AverageLag"), |
| ElementsAre(Bucket(23, 1))); |
| |
| // Only the ScrollUpdate events from frame 2 are sent (as the frame 3 is |
| // waiting for the next frame for sumission). |
| // As there is a scroll update right at the same time as the frame submission, |
| // frame 2 starts with 0 lag at 0.4s and finishes with 100 at 1.4, thus: |
| // 0.5 * (0 + 100) / 2 = 50. It gets into the same bin as 47. |
| EXPECT_THAT(histogram_tester_->GetAllSamples( |
| "Event.Latency.ScrollUpdate.Touch.AverageLag"), |
| ElementsAre(Bucket(47, 1))); |
| } |
| |
| } // namespace |
| } // namespace cc |