diff options
author | Allan Sandfeld Jensen <allan.jensen@qt.io> | 2020-10-29 10:46:47 +0100 |
---|---|---|
committer | Allan Sandfeld Jensen <allan.jensen@qt.io> | 2020-11-02 12:02:10 +0000 |
commit | 99677208ff3b216fdfec551fbe548da5520cd6fb (patch) | |
tree | 476a4865c10320249360e859d8fdd3e01833b03a /chromium/ui/latency | |
parent | c30a6232df03e1efbd9f3b226777b07e087a1122 (diff) | |
download | qtwebengine-chromium-99677208ff3b216fdfec551fbe548da5520cd6fb.tar.gz |
BASELINE: Update Chromium to 86.0.4240.124
Change-Id: Ide0ff151e94cd665ae6521a446995d34a9d1d644
Reviewed-by: Allan Sandfeld Jensen <allan.jensen@qt.io>
Diffstat (limited to 'chromium/ui/latency')
-rw-r--r-- | chromium/ui/latency/BUILD.gn | 12 | ||||
-rw-r--r-- | chromium/ui/latency/average_lag_tracker.cc | 220 | ||||
-rw-r--r-- | chromium/ui/latency/average_lag_tracker.h | 106 | ||||
-rw-r--r-- | chromium/ui/latency/average_lag_tracker_unittest.cc | 540 | ||||
-rw-r--r-- | chromium/ui/latency/latency_info.dot | 14 | ||||
-rw-r--r-- | chromium/ui/latency/latency_tracker.cc | 5 | ||||
-rw-r--r-- | chromium/ui/latency/latency_tracker.h | 3 |
7 files changed, 7 insertions, 893 deletions
diff --git a/chromium/ui/latency/BUILD.gn b/chromium/ui/latency/BUILD.gn index 0e3639e5cd0..5130c405ed9 100644 --- a/chromium/ui/latency/BUILD.gn +++ b/chromium/ui/latency/BUILD.gn @@ -2,13 +2,10 @@ # Use of this source code is governed by a BSD-style license that can be # found in the LICENSE file. -import("//build/config/jumbo.gni") import("//testing/test.gni") -jumbo_source_set("latency") { +source_set("latency") { sources = [ - "average_lag_tracker.cc", - "average_lag_tracker.h", "latency_histogram_macros.h", "latency_info.cc", "latency_info.h", @@ -25,7 +22,7 @@ jumbo_source_set("latency") { public_deps = [ "//services/metrics/public/cpp:metrics_cpp" ] } -jumbo_source_set("test_support") { +source_set("test_support") { testonly = true sources = [ "latency_info_test_support.cc" ] @@ -33,10 +30,7 @@ jumbo_source_set("test_support") { } test("latency_unittests") { - sources = [ - "average_lag_tracker_unittest.cc", - "latency_info_unittest.cc", - ] + sources = [ "latency_info_unittest.cc" ] deps = [ ":latency", diff --git a/chromium/ui/latency/average_lag_tracker.cc b/chromium/ui/latency/average_lag_tracker.cc deleted file mode 100644 index 347b32d3050..00000000000 --- a/chromium/ui/latency/average_lag_tracker.cc +++ /dev/null @@ -1,220 +0,0 @@ -// Copyright 2019 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 "ui/latency/average_lag_tracker.h" - -#include "base/metrics/histogram_functions.h" - -namespace ui { - -AverageLagTracker::AverageLagTracker() = default; - -AverageLagTracker::~AverageLagTracker() = default; - -void AverageLagTracker::AddLatencyInFrame( - const ui::LatencyInfo& latency, - base::TimeTicks gpu_swap_begin_timestamp, - const std::string& scroll_name) { - base::TimeTicks event_timestamp; - bool found_component = latency.FindLatency( - ui::INPUT_EVENT_LATENCY_SCROLL_UPDATE_LAST_EVENT_COMPONENT, - &event_timestamp); - DCHECK(found_component); - // Skip if no event timestamp. - if (!found_component) - return; - - if (scroll_name == "ScrollBegin") { - AddScrollBeginInFrame(gpu_swap_begin_timestamp, event_timestamp); - } else if (scroll_name == "ScrollUpdate" && - !last_event_timestamp_.is_null()) { - AddScrollUpdateInFrame(latency, gpu_swap_begin_timestamp, event_timestamp); - } - - last_event_timestamp_ = event_timestamp; - last_event_accumulated_delta_ += latency.scroll_update_delta(); - last_rendered_accumulated_delta_ += latency.predicted_scroll_update_delta(); -} - -void AverageLagTracker::AddScrollBeginInFrame( - base::TimeTicks gpu_swap_begin_timestamp, - base::TimeTicks event_timestamp) { - // Flush all unfinished frames. - while (!frame_lag_infos_.empty()) { - frame_lag_infos_.front().lag_area += LagForUnfinishedFrame( - frame_lag_infos_.front().rendered_accumulated_delta); - frame_lag_infos_.front().lag_area_no_prediction += LagForUnfinishedFrame( - frame_lag_infos_.front().rendered_accumulated_delta_no_prediction); - - // Record UMA when it's the last item in queue. - CalculateAndReportAverageLagUma(frame_lag_infos_.size() == 1); - } - // |accumulated_lag_| should be cleared/reset. - DCHECK(accumulated_lag_ == 0); - - // Create ScrollBegin report, with report time equals to gpu swap time. - LagAreaInFrame first_frame(gpu_swap_begin_timestamp); - frame_lag_infos_.push_back(first_frame); - - // Reset fields. - last_reported_time_ = event_timestamp; - last_finished_frame_time_ = event_timestamp; - last_event_accumulated_delta_ = 0; - last_rendered_accumulated_delta_ = 0; - is_begin_ = true; -} - -void AverageLagTracker::AddScrollUpdateInFrame( - const LatencyInfo& latency, - base::TimeTicks gpu_swap_begin_timestamp, - base::TimeTicks event_timestamp) { - // Only accept events in nondecreasing order. - if ((event_timestamp - last_event_timestamp_).InMilliseconds() < 0) - return; - - // Pop all frames where frame_time <= event_timestamp. - while (!frame_lag_infos_.empty() && - frame_lag_infos_.front().frame_time <= event_timestamp) { - base::TimeTicks front_time = - std::max(last_event_timestamp_, last_finished_frame_time_); - base::TimeTicks back_time = frame_lag_infos_.front().frame_time; - frame_lag_infos_.front().lag_area += - LagBetween(front_time, back_time, latency, event_timestamp, - frame_lag_infos_.front().rendered_accumulated_delta); - frame_lag_infos_.front().lag_area_no_prediction += LagBetween( - front_time, back_time, latency, event_timestamp, - frame_lag_infos_.front().rendered_accumulated_delta_no_prediction); - - CalculateAndReportAverageLagUma(); - } - - // Initialize a new LagAreaInFrame when current_frame_time > frame_time. - if (frame_lag_infos_.empty() || - gpu_swap_begin_timestamp > frame_lag_infos_.back().frame_time) { - LagAreaInFrame new_frame(gpu_swap_begin_timestamp, - last_rendered_accumulated_delta_, - last_event_accumulated_delta_); - frame_lag_infos_.push_back(new_frame); - } - - // last_frame_time <= event_timestamp < frame_time - if (!frame_lag_infos_.empty()) { - // The front element in queue (if any) must satisfy frame_time > - // event_timestamp, otherwise it would be popped in the while loop. - DCHECK(last_finished_frame_time_ <= event_timestamp && - event_timestamp <= frame_lag_infos_.front().frame_time); - base::TimeTicks front_time = - std::max(last_finished_frame_time_, last_event_timestamp_); - base::TimeTicks back_time = event_timestamp; - - frame_lag_infos_.front().lag_area += - LagBetween(front_time, back_time, latency, event_timestamp, - frame_lag_infos_.front().rendered_accumulated_delta); - - frame_lag_infos_.front().lag_area_no_prediction += LagBetween( - front_time, back_time, latency, event_timestamp, - frame_lag_infos_.front().rendered_accumulated_delta_no_prediction); - } -} - -float AverageLagTracker::LagBetween(base::TimeTicks front_time, - base::TimeTicks back_time, - const LatencyInfo& latency, - base::TimeTicks event_timestamp, - float rendered_accumulated_delta) { - // In some tests, we use const event time. return 0 to avoid divided by 0. - if (event_timestamp == last_event_timestamp_) - return 0; - - float front_delta = - (last_event_accumulated_delta_ + - (latency.scroll_update_delta() * - ((front_time - last_event_timestamp_).InMillisecondsF() / - (event_timestamp - last_event_timestamp_).InMillisecondsF()))) - - rendered_accumulated_delta; - - float back_delta = - (last_event_accumulated_delta_ + - latency.scroll_update_delta() * - - ((back_time - last_event_timestamp_).InMillisecondsF() / - (event_timestamp - last_event_timestamp_).InMillisecondsF())) - - rendered_accumulated_delta; - - // Calculate the trapezoid area. - if (front_delta * back_delta >= 0) { - return 0.5f * std::abs(front_delta + back_delta) * - (back_time - front_time).InMillisecondsF(); - } - - // Corner case that rendered_accumulated_delta is in between of front_pos - // and back_pos. - return 0.5f * - std::abs((front_delta * front_delta + back_delta * back_delta) / - (back_delta - front_delta)) * - (back_time - front_time).InMillisecondsF(); -} - -float AverageLagTracker::LagForUnfinishedFrame( - float rendered_accumulated_delta) { - base::TimeTicks last_time = - std::max(last_event_timestamp_, last_finished_frame_time_); - return std::abs(last_event_accumulated_delta_ - rendered_accumulated_delta) * - (frame_lag_infos_.front().frame_time - last_time).InMillisecondsF(); -} - -void AverageLagTracker::CalculateAndReportAverageLagUma(bool send_anyway) { - DCHECK(!frame_lag_infos_.empty()); - const LagAreaInFrame& frame_lag = frame_lag_infos_.front(); - - DCHECK(frame_lag.lag_area >= 0.f); - DCHECK(frame_lag.lag_area_no_prediction >= 0.f); - accumulated_lag_ += frame_lag.lag_area; - accumulated_lag_no_prediction_ += frame_lag.lag_area_no_prediction; - - if (is_begin_) { - DCHECK(accumulated_lag_ == accumulated_lag_no_prediction_); - } - - // |send_anyway| is true when we are flush all remaining frames on next - // |ScrollBegin|. Otherwise record UMA when it's ScrollBegin, or when - // reaching the 1 second gap. - if (send_anyway || is_begin_ || - (frame_lag.frame_time - last_reported_time_).InSecondsF() >= 1.0f) { - std::string scroll_name = is_begin_ ? "ScrollBegin" : "ScrollUpdate"; - const float time_delta = - (frame_lag.frame_time - last_reported_time_).InMillisecondsF(); - const float scaled_lag = accumulated_lag_ / time_delta; - base::UmaHistogramCounts1000( - "Event.Latency." + scroll_name + ".Touch.AverageLag", scaled_lag); - - const float prediction_effect = - (accumulated_lag_no_prediction_ - accumulated_lag_) / time_delta; - // Log positive and negative prediction effects. ScrollBegin currently - // doesn't take prediction into account so don't log for it. - // Positive effect means that the prediction reduced the perceived lag, - // where negative means prediction made lag worse (most likely due to - // misprediction). - if (!is_begin_) { - if (prediction_effect >= 0.f) { - base::UmaHistogramCounts1000( - "Event.Latency.ScrollUpdate.Touch.AverageLag.PredictionPositive", - prediction_effect); - } else { - base::UmaHistogramCounts1000( - "Event.Latency.ScrollUpdate.Touch.AverageLag.PredictionNegative", - -prediction_effect); - } - } - accumulated_lag_ = 0; - accumulated_lag_no_prediction_ = 0; - last_reported_time_ = frame_lag.frame_time; - is_begin_ = false; - } - - last_finished_frame_time_ = frame_lag.frame_time; - frame_lag_infos_.pop_front(); -} - -} // namespace ui diff --git a/chromium/ui/latency/average_lag_tracker.h b/chromium/ui/latency/average_lag_tracker.h deleted file mode 100644 index f97738f17cf..00000000000 --- a/chromium/ui/latency/average_lag_tracker.h +++ /dev/null @@ -1,106 +0,0 @@ -// Copyright 2019 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. - -#ifndef UI_LATENCY_AVERAGE_LAG_TRACKER_H_ -#define UI_LATENCY_AVERAGE_LAG_TRACKER_H_ - -#include <deque> - -#include "base/macros.h" -#include "ui/latency/latency_info.h" - -namespace ui { - -// A class for reporting AverageLag metrics. See -// https://docs.google.com/document/d/1e8NuzPblIv2B9bz01oSj40rmlse7_PHq5oFS3lqz6N4/ -class AverageLagTracker { - public: - AverageLagTracker(); - ~AverageLagTracker(); - void AddLatencyInFrame(const LatencyInfo& latency, - base::TimeTicks gpu_swap_begin_timestamp, - const std::string& scroll_name); - - private: - typedef struct LagAreaInFrame { - LagAreaInFrame(base::TimeTicks time, - float rendered_pos = 0, - float rendered_pos_no_prediction = 0) - : frame_time(time), - rendered_accumulated_delta(rendered_pos), - lag_area(0), - rendered_accumulated_delta_no_prediction(rendered_pos_no_prediction), - lag_area_no_prediction(0) {} - base::TimeTicks frame_time; - // |rendered_accumulated_delta| is the cumulative delta that was swapped for - // this frame; this is based on the predicted delta, if prediction is - // enabled. - float rendered_accumulated_delta; - // |lag_area| is computed once a future input is processed that occurs after - // the swap timestamp (so that we can compute how far the rendered delta - // was from the actual position at the swap time). - float lag_area; - // |rendered_accumulated_delta_no_prediction| is the what would have been - // rendered if prediction was not taken into account, i.e., the actual delta - // from the input event. - float rendered_accumulated_delta_no_prediction; - // |lag_area_no_prediction| is computed the same as |lag_area| but using - // rendered_accumulated_delta_no_prediction as the rendered delta. - float lag_area_no_prediction; - } LagAreaInFrame; - - void AddScrollBeginInFrame(base::TimeTicks gpu_swap_begin_timestamp, - base::TimeTicks event_timestamp); - void AddScrollUpdateInFrame(const LatencyInfo& latency, - base::TimeTicks gpu_swap_begin_timestamp, - base::TimeTicks event_timestamp); - - // Calculate lag in 1 seconds intervals and report UMA. - void CalculateAndReportAverageLagUma(bool send_anyway = false); - - // Helper function to calculate lag area between |front_time| to - // |back_time|. - float LagBetween(base::TimeTicks front_time, - base::TimeTicks back_time, - const LatencyInfo& latency, - base::TimeTicks event_time, - float rendered_accumulated_delta); - - float LagForUnfinishedFrame(float rendered_accumulated_delta); - - std::deque<LagAreaInFrame> frame_lag_infos_; - - // Last scroll event's timestamp in the sequence, reset on ScrollBegin. - base::TimeTicks last_event_timestamp_; - // Timestamp of the last frame popped from |frame_lag_infos_| queue. - base::TimeTicks last_finished_frame_time_; - - // Accumulated scroll delta for actual scroll update events. Cumulated from - // latency.scroll_update_delta(). Reset on ScrollBegin. - float last_event_accumulated_delta_ = 0; - // Accumulated scroll delta got rendered on gpu swap. Cumulated from - // latency.predicted_scroll_update_delta(). It always has same value as - // |last_event_accumulated_delta_| when scroll prediction is disabled. - float last_rendered_accumulated_delta_ = 0; - - // This keeps track of the last report_time when we report to UMA, so we can - // calculate the report's duration by current - last. Reset on ScrollBegin. - base::TimeTicks last_reported_time_; - - // True if the first element of |frame_lag_infos_| is for ScrollBegin. - // For ScrollBegin, we don't wait for the 1 second interval but record the - // UMA once the frame is finished. - bool is_begin_ = false; - - // Accumulated lag area in the 1 second intervals. - float accumulated_lag_ = 0; - // Accumulated lag not taking into account the predicted deltas. - float accumulated_lag_no_prediction_ = 0; - - DISALLOW_COPY_AND_ASSIGN(AverageLagTracker); -}; - -} // namespace ui - -#endif // UI_LATENCY_AVERAGE_LAG_TRACKER_H_ diff --git a/chromium/ui/latency/average_lag_tracker_unittest.cc b/chromium/ui/latency/average_lag_tracker_unittest.cc deleted file mode 100644 index e2a0f223e60..00000000000 --- a/chromium/ui/latency/average_lag_tracker_unittest.cc +++ /dev/null @@ -1,540 +0,0 @@ -// Copyright 2019 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 "ui/latency/average_lag_tracker.h" - -#include "base/test/metrics/histogram_tester.h" -#include "testing/gmock/include/gmock/gmock.h" -#include "testing/gtest/include/gtest/gtest.h" - -using base::Bucket; -using testing::ElementsAre; - -namespace ui { -namespace { - -class AverageLagTrackerTest : public testing::Test { - public: - AverageLagTrackerTest() { ResetHistograms(); } - - void ResetHistograms() { - histogram_tester_ = std::make_unique<base::HistogramTester>(); - } - - const base::HistogramTester& histogram_tester() { return *histogram_tester_; } - - void SetUp() override { - average_lag_tracker_ = std::make_unique<AverageLagTracker>(); - } - - void SyntheticTouchScrollBeginLatencyInfo(base::TimeTicks event_time, - base::TimeTicks frame_time, - float delta, - float predicted_delta = 0) { - ui::LatencyInfo touch_latency(ui::SourceEventType::TOUCH); - touch_latency.set_scroll_update_delta(delta); - touch_latency.set_predicted_scroll_update_delta( - predicted_delta != 0 ? predicted_delta : delta); - - touch_latency.AddLatencyNumberWithTimestamp( - ui::INPUT_EVENT_LATENCY_FIRST_SCROLL_UPDATE_ORIGINAL_COMPONENT, - event_time); - touch_latency.AddLatencyNumberWithTimestamp( - ui::INPUT_EVENT_LATENCY_SCROLL_UPDATE_LAST_EVENT_COMPONENT, event_time); - average_lag_tracker_->AddLatencyInFrame(touch_latency, frame_time, - "ScrollBegin"); - } - - void SyntheticTouchScrollUpdateLatencyInfo(base::TimeTicks event_time, - base::TimeTicks frame_time, - float delta, - float predicted_delta = 0) { - ui::LatencyInfo touch_latency(ui::SourceEventType::TOUCH); - touch_latency.set_scroll_update_delta(delta); - touch_latency.set_predicted_scroll_update_delta( - predicted_delta != 0 ? predicted_delta : delta); - touch_latency.AddLatencyNumberWithTimestamp( - ui::INPUT_EVENT_LATENCY_SCROLL_UPDATE_ORIGINAL_COMPONENT, event_time); - touch_latency.AddLatencyNumberWithTimestamp( - ui::INPUT_EVENT_LATENCY_SCROLL_UPDATE_LAST_EVENT_COMPONENT, event_time); - average_lag_tracker_->AddLatencyInFrame(touch_latency, frame_time, - "ScrollUpdate"); - } - - protected: - std::unique_ptr<AverageLagTracker> average_lag_tracker_; - - std::unique_ptr<base::HistogramTester> histogram_tester_; -}; - -base::TimeTicks MillisecondsToTimeTicks(float t_ms) { - return base::TimeTicks() + base::TimeDelta::FromMilliseconds(t_ms); -} - -// 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. -TEST_F(AverageLagTrackerTest, OneSecondInterval) { - base::TimeTicks event_time = - base::TimeTicks() + base::TimeDelta::FromMilliseconds(5); - base::TimeTicks frame_time = - base::TimeTicks() + base::TimeDelta::FromMilliseconds(10); - float scroll_delta = 10; - - // ScrollBegin - event_time += base::TimeDelta::FromMilliseconds(10); // 15ms - frame_time += base::TimeDelta::FromMilliseconds(10); // 20ms - SyntheticTouchScrollBeginLatencyInfo(event_time, frame_time, scroll_delta); - - // 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 negetive delta. - const int sign = (i < kUpdates / 2) ? 1 : -1; - SyntheticTouchScrollUpdateLatencyInfo(event_time, frame_time, - sign * scroll_delta); - } - - // 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, - base::TimeTicks() + base::TimeDelta::FromMilliseconds(1025)); - EXPECT_EQ(frame_time, - base::TimeTicks() + base::TimeDelta::FromMilliseconds(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); - SyntheticTouchScrollBeginLatencyInfo(event_time, frame_time, scroll_delta); - - // 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); -} - -// Test the case that event's frame swap time is later than next event's -// creation time. (i.e, event at t=10ms will be dispatch at t=30ms, while next -// event is at t=20ms). -TEST_F(AverageLagTrackerTest, LargerLatency) { - base::TimeTicks event_time = MillisecondsToTimeTicks(10); - base::TimeTicks frame_time = - event_time + base::TimeDelta::FromMilliseconds(20); - float scroll_delta = 10; - - SyntheticTouchScrollBeginLatencyInfo(event_time, frame_time, scroll_delta); - - // Send 2 ScrollUpdate. The second one will record AverageLag.ScrollBegin as - // it's event_time is larger or equal to ScrollBegin's frame_time. - for (int i = 0; i < 2; i++) { - event_time += base::TimeDelta::FromMilliseconds(10); - frame_time = event_time + base::TimeDelta::FromMilliseconds(20); - SyntheticTouchScrollUpdateLatencyInfo(event_time, frame_time, scroll_delta); - } - - // ScrollBegin AveragLag are from t=10ms to t=30ms, with absolute scroll - // position from 10 to 30. The AverageLag should be: - // (0.5*(10px + 30px)*20ms/20ms) = 20px. - EXPECT_THAT(histogram_tester().GetAllSamples( - "Event.Latency.ScrollBegin.Touch.AverageLag"), - ElementsAre(Bucket(20, 1))); - - // Another ScrollBegin to flush unfinished frames. - // event_time doesn't matter here because the previous frames' lag are - // compute from their frame_time. - event_time = MillisecondsToTimeTicks(1000); - frame_time = MillisecondsToTimeTicks(1000); - SyntheticTouchScrollBeginLatencyInfo(event_time, frame_time, scroll_delta); - // The to unfinished frames' lag are (finger_positon-rendered_position)*time, - // AverageLag is ((30px-10px)*10ms+(30px-20px)*10ms)/20ms = 15px. - EXPECT_THAT(histogram_tester().GetAllSamples( - "Event.Latency.ScrollUpdate.Touch.AverageLag"), - ElementsAre(Bucket(14, 1))); -} - -// Test that multiple latency being flush in the same frame swap. -TEST_F(AverageLagTrackerTest, TwoLatencyInfoInSameFrame) { - // ScrollBegin - base::TimeTicks event_time = MillisecondsToTimeTicks(10); - base::TimeTicks frame_time = MillisecondsToTimeTicks(20); - SyntheticTouchScrollBeginLatencyInfo(event_time, frame_time, - -10 /* scroll_delta */); - - // ScrollUpdate with event_time >= ScrollBegin frame_time will generate - // a histogram for AverageLag.ScrollBegin. - event_time = MillisecondsToTimeTicks(20); - frame_time = MillisecondsToTimeTicks(30); - SyntheticTouchScrollUpdateLatencyInfo(event_time, frame_time, - -10 /* scroll_delta */); - - // Absolute position from -10 to -20. The AverageLag should be: - // (0.5*(10px + 20px)*10ms/10ms) = 15px. - EXPECT_THAT(histogram_tester().GetAllSamples( - "Event.Latency.ScrollBegin.Touch.AverageLag"), - ElementsAre(Bucket(14, 1))); - - event_time = MillisecondsToTimeTicks(25); - frame_time = MillisecondsToTimeTicks(30); - SyntheticTouchScrollUpdateLatencyInfo(event_time, frame_time, - 5 /* scroll_delta */); - - // Another ScrollBegin to flush unfinished frames. - event_time = MillisecondsToTimeTicks(1000); - frame_time = MillisecondsToTimeTicks(1000); - SyntheticTouchScrollBeginLatencyInfo(event_time, frame_time, 0); - - // The ScrollUpdates are at t=20ms, finger_pos=-20px, rendered_pos=-10px, - // at t=25ms, finger_pos=-15px, rendered_pos=-10px; - // To t=30ms both events get flush. - // AverageLag is (0.5*(10px+5px)*5ms + 5px*5ms)/10ms = 6.25px - EXPECT_THAT(histogram_tester().GetAllSamples( - "Event.Latency.ScrollUpdate.Touch.AverageLag"), - ElementsAre(Bucket(6, 1))); -} - -// Test the case that switching direction causes lag at current frame -// time and previous frame time are in different direction. -TEST_F(AverageLagTrackerTest, ChangeDirectionInFrame) { - // ScrollBegin - base::TimeTicks event_time = MillisecondsToTimeTicks(10); - base::TimeTicks frame_time = MillisecondsToTimeTicks(20); - SyntheticTouchScrollBeginLatencyInfo(event_time, frame_time, - 10 /* scroll_delta */); - - // At t=20, lag = 10px. - event_time = MillisecondsToTimeTicks(20); - frame_time = MillisecondsToTimeTicks(30); - SyntheticTouchScrollUpdateLatencyInfo(event_time, frame_time, - 10 /* scroll_delta */); - - // At t=30, lag = -10px. - event_time = MillisecondsToTimeTicks(30); - frame_time = MillisecondsToTimeTicks(40); - SyntheticTouchScrollUpdateLatencyInfo(event_time, frame_time, - -20 /* scroll_delta */); - - // Another ScrollBegin to flush unfinished frames. - event_time = MillisecondsToTimeTicks(1000); - frame_time = MillisecondsToTimeTicks(1000); - SyntheticTouchScrollBeginLatencyInfo(event_time, frame_time, 0); - - // From t=20 to t=30, lag_area=2*(0.5*10px*5ms)=50px*ms. - // From t=30 to t=40, lag_area=20px*10ms=200px*ms - // AverageLag = (50+200)/20 = 12.5px. - EXPECT_THAT(histogram_tester().GetAllSamples( - "Event.Latency.ScrollUpdate.Touch.AverageLag"), - ElementsAre(Bucket(12, 1))); -} - -// A simple case without scroll prediction to compare with the two with -// prediction cases below. -TEST_F(AverageLagTrackerTest, NoScrollPrediction) { - // ScrollBegin, at t=5, finger_pos=5px. - base::TimeTicks event_time = MillisecondsToTimeTicks(5); - base::TimeTicks frame_time = MillisecondsToTimeTicks(10); - SyntheticTouchScrollBeginLatencyInfo(event_time, frame_time, - 5 /* scroll_delta */); - - // ScrollUpdate, at t=15, finger_pos=15px. - event_time = MillisecondsToTimeTicks(15); - frame_time = MillisecondsToTimeTicks(20); - SyntheticTouchScrollUpdateLatencyInfo(event_time, frame_time, - 10 /* scroll_delta */); - - // ScrollUpdate, at t=25, finger_pos=25px. - event_time = MillisecondsToTimeTicks(25); - frame_time = MillisecondsToTimeTicks(30); - SyntheticTouchScrollUpdateLatencyInfo(event_time, frame_time, - 10 /* scroll_delta */); - - // Another ScrollBegin to flush unfinished frames. - event_time = MillisecondsToTimeTicks(1000); - frame_time = MillisecondsToTimeTicks(1000); - SyntheticTouchScrollBeginLatencyInfo(event_time, frame_time, 0); - - // Prediction hasn't take affect on ScrollBegin so it'll stay the same. - EXPECT_THAT(histogram_tester().GetAllSamples( - "Event.Latency.ScrollBegin.Touch.AverageLag"), - ElementsAre(Bucket(7, 1))); - // At t=10, finger_pos = 10px, rendered_pos = 5px. - // At t=20, finger_pos = 20px, rendered_pos = 15px. - // At t=30, finger_pos = 25px, rendered_pos = 25px. - // AverageLag = ((5px+15px)*10ms/2 + (5px+10px)*5ms/2 + 10px*5ms)/20ms - // = 9.375 - EXPECT_THAT(histogram_tester().GetAllSamples( - "Event.Latency.ScrollUpdate.Touch.AverageLag"), - ElementsAre(Bucket(9, 1))); -} - -// Test AverageLag with perfect scroll prediction. -TEST_F(AverageLagTrackerTest, ScrollPrediction) { - // ScrollBegin, at t=5, finger_pos=5px. - // Predict frame_time=10, predicted_pos = 10px. - base::TimeTicks event_time = MillisecondsToTimeTicks(5); - base::TimeTicks frame_time = MillisecondsToTimeTicks(10); - SyntheticTouchScrollBeginLatencyInfo( - event_time, frame_time, 5 /* scroll_delta */, 10 /* predicted_delta */); - - // ScrollUpdate, at t=15, finger_pos=15px. - // Predict frame_time=20, predicted_pos = 20px. - event_time = MillisecondsToTimeTicks(15); - frame_time = MillisecondsToTimeTicks(20); - SyntheticTouchScrollUpdateLatencyInfo( - event_time, frame_time, 10 /* scroll_delta */, 10 /* predicted_delta */); - - // ScrollUpdate, at t=25, finger_pos=25px. - // Predict frame_time=30, predicted_pos = 30px. - event_time = MillisecondsToTimeTicks(25); - frame_time = MillisecondsToTimeTicks(30); - SyntheticTouchScrollUpdateLatencyInfo( - event_time, frame_time, 10 /* scroll_delta */, 10 /* predicted_delta */); - - // Another ScrollBegin to flush unfinished frames. - event_time = MillisecondsToTimeTicks(1000); - frame_time = MillisecondsToTimeTicks(1000); - SyntheticTouchScrollBeginLatencyInfo(event_time, frame_time, 0); - - // Prediction hasn't take affect on ScrollBegin so it'll stay the same. - EXPECT_THAT(histogram_tester().GetAllSamples( - "Event.Latency.ScrollBegin.Touch.AverageLag"), - ElementsAre(Bucket(7, 1))); - // At t=10, finger_pos = 10px, rendered_pos = 10px. - // At t=20, finger_pos = 20px, rendered_pos = 20px. - // At t=30, finger_pos = 25px, rendered_pos = 30px. - // AverageLag = ((0px+10px)*10ms/2 + (0px+5px)*10ms/2 + 5px*5ms)/20ms - // = 4.375px - // AverageLag (w/o prediction) - // ((5px+15px)*10ms/2 + (5px+10px)*5ms/2 + 10px*5ms)/20ms - // = 9.375px - // Positive effect of prediction = 5px - EXPECT_THAT(histogram_tester().GetAllSamples( - "Event.Latency.ScrollUpdate.Touch.AverageLag"), - ElementsAre(Bucket(4, 1))); - EXPECT_THAT( - histogram_tester().GetAllSamples( - "Event.Latency.ScrollUpdate.Touch.AverageLag.PredictionPositive"), - ElementsAre(Bucket(5, 1))); - histogram_tester().ExpectTotalCount( - "Event.Latency.ScrollUpdate.Touch.AverageLag.PredictionNegative", 0); -} - -// Test AverageLag with imperfect scroll prediction. -TEST_F(AverageLagTrackerTest, ImperfectScrollPrediction) { - // ScrollBegin, at t=5, finger_pos=5px. - // Predict frame_time=10, predicted_pos(over) = 12px. - base::TimeTicks event_time = MillisecondsToTimeTicks(5); - base::TimeTicks frame_time = MillisecondsToTimeTicks(10); - SyntheticTouchScrollBeginLatencyInfo( - event_time, frame_time, 5 /* scroll_delta */, 12 /* predicted_delta */); - - // ScrollUpdate, at t=15, finger_pos=15px. - // Predict frame_time=20, predicted_pos(under) = 17px. - event_time = MillisecondsToTimeTicks(15); - frame_time = MillisecondsToTimeTicks(20); - SyntheticTouchScrollUpdateLatencyInfo( - event_time, frame_time, 10 /* scroll_delta */, 5 /* predicted_delta */); - - // ScrollUpdate, at t=25, finger_pos=25px. - // Predict frame_time=30, predicted_pos(over) = 31px. - event_time = MillisecondsToTimeTicks(25); - frame_time = MillisecondsToTimeTicks(30); - SyntheticTouchScrollUpdateLatencyInfo( - event_time, frame_time, 10 /* scroll_delta */, 14 /* predicted_delta */); - - // Another ScrollBegin to flush unfinished frames. - event_time = MillisecondsToTimeTicks(1000); - frame_time = MillisecondsToTimeTicks(1000); - SyntheticTouchScrollBeginLatencyInfo(event_time, frame_time, 0); - - EXPECT_THAT(histogram_tester().GetAllSamples( - "Event.Latency.ScrollBegin.Touch.AverageLag"), - ElementsAre(Bucket(7, 1))); - // AverageLag = ((2px*2ms/2+8px*8ms/2)+ ((3px+8px)*5ms/2+8px*5ms))/20ms - // = 5.075px - EXPECT_THAT(histogram_tester().GetAllSamples( - "Event.Latency.ScrollUpdate.Touch.AverageLag"), - ElementsAre(Bucket(5, 1))); - // AverageLag (w/o prediction = - // ((5px+15px)*10ms/2 + (5px+10px)*5ms/2 + 10px*5ms)/20ms - // = 9.375px - // Positive effect of prediction = 4.3px - EXPECT_THAT( - histogram_tester().GetAllSamples( - "Event.Latency.ScrollUpdate.Touch.AverageLag.PredictionPositive"), - ElementsAre(Bucket(4, 1))); - histogram_tester().ExpectTotalCount( - "Event.Latency.ScrollUpdate.Touch.AverageLag.PredictionNegative", 0); -} - -TEST_F(AverageLagTrackerTest, NegativePredictionEffect) { - // ScrollBegin, at t=5, finger_pos=5px. - // Predict frame_time=10, predicted_pos(over) = 20px. - base::TimeTicks event_time = MillisecondsToTimeTicks(5); - base::TimeTicks frame_time = MillisecondsToTimeTicks(10); - SyntheticTouchScrollBeginLatencyInfo( - event_time, frame_time, 5 /* scroll_delta */, 20 /* predicted_delta */); - - // ScrollUpdate, at t=15, finger_pos=15px. - // Predict frame_time=20, predicted_pos(over) = 60px. - event_time = MillisecondsToTimeTicks(15); - frame_time = MillisecondsToTimeTicks(20); - SyntheticTouchScrollUpdateLatencyInfo( - event_time, frame_time, 10 /* scroll_delta */, 40 /* predicted_delta */); - - // ScrollUpdate, at t=25, finger_pos=25px. - // Predict frame_time=30, predicted_pos(over) = 60px. - event_time = MillisecondsToTimeTicks(25); - frame_time = MillisecondsToTimeTicks(30); - SyntheticTouchScrollUpdateLatencyInfo( - event_time, frame_time, 10 /* scroll_delta */, 0 /* predicted_delta */); - - // Another ScrollBegin to flush unfinished frames. - event_time = MillisecondsToTimeTicks(1000); - frame_time = MillisecondsToTimeTicks(1000); - SyntheticTouchScrollBeginLatencyInfo(event_time, frame_time, 0); - - EXPECT_THAT(histogram_tester().GetAllSamples( - "Event.Latency.ScrollBegin.Touch.AverageLag"), - ElementsAre(Bucket(7, 1))); - // AverageLag = ((10px+0px)*10ms/2)+ ((40px+35px)*5ms/2+35px*5ms))/20ms - // = 20.625px - EXPECT_THAT(histogram_tester().GetAllSamples( - "Event.Latency.ScrollUpdate.Touch.AverageLag"), - ElementsAre(Bucket(20, 1))); - // AverageLag (w/o prediction = - // ((5px+15px)*10ms/2 + (5px+10px)*5ms/2 + 10px*5ms)/20ms - // = 9.375px - // Negative effect of prediction = 11.25 - histogram_tester().ExpectTotalCount( - "Event.Latency.ScrollUpdate.Touch.AverageLag.PredictionPositive", 0); - EXPECT_THAT( - histogram_tester().GetAllSamples( - "Event.Latency.ScrollUpdate.Touch.AverageLag.PredictionNegative"), - ElementsAre(Bucket(11, 1))); -} - -TEST_F(AverageLagTrackerTest, NoPredictionEffect) { - // ScrollBegin, at t=5, finger_pos=5px. - // Predict frame_time=10, predicted_pos(over) = 25px. - base::TimeTicks event_time = MillisecondsToTimeTicks(5); - base::TimeTicks frame_time = MillisecondsToTimeTicks(10); - SyntheticTouchScrollBeginLatencyInfo( - event_time, frame_time, 5 /* scroll_delta */, 25 /* predicted_delta */); - - // ScrollUpdate, at t=15, finger_pos=15px. - // Predict frame_time=20, predicted_pos(over) = 32px. - event_time = MillisecondsToTimeTicks(15); - frame_time = MillisecondsToTimeTicks(20); - SyntheticTouchScrollUpdateLatencyInfo( - event_time, frame_time, 10 /* scroll_delta */, 7 /* predicted_delta */); - - // ScrollUpdate, at t=25, finger_pos=25px. - // Predict frame_time=30, predicted_pos(over) = 37px. - event_time = MillisecondsToTimeTicks(25); - frame_time = MillisecondsToTimeTicks(30); - SyntheticTouchScrollUpdateLatencyInfo( - event_time, frame_time, 10 /* scroll_delta */, 5 /* predicted_delta */); - - // Another ScrollBegin to flush unfinished frames. - event_time = MillisecondsToTimeTicks(1000); - frame_time = MillisecondsToTimeTicks(1000); - SyntheticTouchScrollBeginLatencyInfo(event_time, frame_time, 0); - - EXPECT_THAT(histogram_tester().GetAllSamples( - "Event.Latency.ScrollBegin.Touch.AverageLag"), - ElementsAre(Bucket(7, 1))); - // AverageLag = ((15px+5px)*10ms/2 + (12px+7px)*5ms/2 + 7px*5ms)/20ms - // = 9.125px - EXPECT_THAT(histogram_tester().GetAllSamples( - "Event.Latency.ScrollUpdate.Touch.AverageLag"), - ElementsAre(Bucket(9, 1))); - // AverageLag (w/o prediction) = - // ((5px+15px)*10ms/2 + (5px+10px)*5ms/2 + 10px*5ms)/20ms - // = 9.375px - // Prediction slightly positive, we should see a 0 bucket in - // PredictionPositive UMA - 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); -} - -// Tests that when an event arrives out-of-order, the average lag tracker -// properly ignores it. -TEST_F(AverageLagTrackerTest, EventOutOfOrder) { - base::TimeTicks event_time = MillisecondsToTimeTicks(5); - base::TimeTicks frame_time = MillisecondsToTimeTicks(10); - float scroll_delta = 5.f; - SyntheticTouchScrollBeginLatencyInfo(event_time, frame_time, scroll_delta); - - event_time = MillisecondsToTimeTicks(15); - frame_time = MillisecondsToTimeTicks(20); - SyntheticTouchScrollUpdateLatencyInfo(event_time, frame_time, scroll_delta); - - event_time = MillisecondsToTimeTicks(25); - frame_time = MillisecondsToTimeTicks(30); - SyntheticTouchScrollUpdateLatencyInfo(event_time, frame_time, scroll_delta); - - // A ScrollBegin to flush unfinished frames. - event_time = MillisecondsToTimeTicks(1000); - frame_time = MillisecondsToTimeTicks(1000); - SyntheticTouchScrollBeginLatencyInfo(event_time, frame_time, 0); - - histogram_tester().ExpectTotalCount( - "Event.Latency.ScrollUpdate.Touch.AverageLag", 1); - - // Send an event whose timestamp is earlier than the most recent event, - // representing an event that gets process out of order. - base::TimeTicks earlier_event_time = MillisecondsToTimeTicks(15); - frame_time = MillisecondsToTimeTicks(1010); - SyntheticTouchScrollUpdateLatencyInfo(earlier_event_time, frame_time, - scroll_delta); - - // Another ScrollBegin to flush unfinished frames. - event_time = MillisecondsToTimeTicks(2000); - frame_time = MillisecondsToTimeTicks(2000); - SyntheticTouchScrollBeginLatencyInfo(event_time, frame_time, 0); - - // Ensure that the event was ignored. - histogram_tester().ExpectTotalCount( - "Event.Latency.ScrollUpdate.Touch.AverageLag", 1); -} - -} // namespace -} // namespace ui diff --git a/chromium/ui/latency/latency_info.dot b/chromium/ui/latency/latency_info.dot index 3490ac1a989..887d4e9eae4 100644 --- a/chromium/ui/latency/latency_info.dot +++ b/chromium/ui/latency/latency_info.dot @@ -8,8 +8,6 @@ digraph LatencyInfo { node[style="dotted,rounded"]; "Event.Latency.EventToRender.TouchpadPinch"; - "Event.Latency.QueueingTime.<event_name><default_action_status>"; - "Event.Latency.BlockingTime.<event_name><default_action_status>"; end_to_end_metrics [label="\ Event.Latency.EndToEnd.KeyPress\n\ @@ -56,11 +54,7 @@ INPUT_EVENT_LATENCY_RENDERING_SCHEDULED_IMPL_COMPONENT"]; // Layout the rest of the components. INPUT_EVENT_LATENCY_ORIGINAL_COMPONENT-> "Event.Latency.EventToRender.TouchpadPinch"-> - INPUT_EVENT_LATENCY_BEGIN_RWH_COMPONENT-> - "Event.Latency.QueueingTime.<event_name><default_action_status>"-> - INPUT_EVENT_LATENCY_RENDERER_MAIN_COMPONENT-> - "Event.Latency.BlockingTime.<event_name><default_action_status>"-> - INPUT_EVENT_LATENCY_ACK_RWH_COMPONENT + INPUT_EVENT_LATENCY_BEGIN_RWH_COMPONENT [weight=3]; INPUT_EVENT_LATENCY_ORIGINAL_COMPONENT-> @@ -94,7 +88,7 @@ INPUT_EVENT_LATENCY_RENDERING_SCHEDULED_IMPL_COMPONENT"]; "Event.Latency.<scroll_name>.Touch.RAFTimeToFrameSwapEnd"-> INPUT_EVENT_LATENCY_FRAME_SWAP_COMPONENT; - // Add legend and position it under INPUT_EVENT_LATENCY_ACK_RWH_COMPONENT. + // Add legend and position it under INPUT_EVENT_LATENCY_BEGIN_RWH_COMPONENT. legend [shape=plaintext,label="\ LEGEND:\l\ @@ -102,7 +96,7 @@ LEGEND:\l\ <input_modality> = (Wheel | Touch)\l\ <scroll_name> = (ScrollBegin | ScrollUpdate)\l\ <thread_name> = (Main | Impl)\l"]; - INPUT_EVENT_LATENCY_ACK_RWH_COMPONENT-> + INPUT_EVENT_LATENCY_BEGIN_RWH_COMPONENT-> legend - [style=invis,minlen=3]; + [style=invis,minlen=7]; } diff --git a/chromium/ui/latency/latency_tracker.cc b/chromium/ui/latency/latency_tracker.cc index a724b21d32e..7f059ff7672 100644 --- a/chromium/ui/latency/latency_tracker.cc +++ b/chromium/ui/latency/latency_tracker.cc @@ -308,11 +308,6 @@ void LatencyTracker::ComputeEndToEndLatencyHistograms( DCHECK_AND_RETURN_ON_FAIL(found_component); } - if (!IsInertialScroll(latency) && input_modality == "Touch") { - average_lag_tracker_.AddLatencyInFrame(latency, gpu_swap_begin_timestamp, - scroll_name); - } - // Inertial and scrollbar scrolls are excluded from Ukm metrics. if ((input_modality == "Touch" && !IsInertialScroll(latency)) || input_modality == "Wheel") { diff --git a/chromium/ui/latency/latency_tracker.h b/chromium/ui/latency/latency_tracker.h index e0bb699a1f3..88f56c4a41b 100644 --- a/chromium/ui/latency/latency_tracker.h +++ b/chromium/ui/latency/latency_tracker.h @@ -7,7 +7,6 @@ #include "base/callback_forward.h" #include "base/macros.h" -#include "ui/latency/average_lag_tracker.h" #include "ui/latency/latency_info.h" namespace ui { @@ -53,8 +52,6 @@ class LatencyTracker { const LatencyInfo& latency, bool top_controls_visible_height_changed); - AverageLagTracker average_lag_tracker_; - DISALLOW_COPY_AND_ASSIGN(LatencyTracker); }; |