cc/metrics/average_lag_tracker.cc - chromium/src - Git at Google

 // Copyright 2019 The Chromium Authors
 // 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_tracker.h"

 #include <algorithm>

 #include "base/metrics/histogram_functions.h"
 #include "base/strings/string_util.h"

 namespace cc {

 AverageLagTracker::AverageLagTracker() = default;
 AverageLagTracker::~AverageLagTracker() = default;

 void AverageLagTracker::AddScrollEventInFrame(const EventInfo& event_info) {
   if (event_info.event_type == EventType::ScrollBegin) {
     AddScrollBeginInFrame(event_info);
   } else if (!last_event_timestamp_.is_null()) {
     AddScrollUpdateInFrame(event_info);
   }

   last_event_timestamp_ = event_info.event_timestamp;
   last_event_accumulated_delta_ += event_info.event_scroll_delta;
   last_rendered_accumulated_delta_ += event_info.predicted_scroll_delta;
 }

 std::string AverageLagTracker::GetAverageLagMetricName(EventType event) const {
   std::string metric_name = "AverageLagPresentation";

   std::string event_name =
       event == EventType::ScrollBegin ? "ScrollBegin" : "ScrollUpdate";

   return base::JoinString(
       {"Event", "Latency", event_name, "Touch", metric_name}, ".");
 }

 void AverageLagTracker::AddScrollBeginInFrame(const EventInfo& event_info) {
   DCHECK_EQ(event_info.event_type, EventType::ScrollBegin);

   // 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_EQ(accumulated_lag_, 0);

   // Create ScrollBegin report, with report time equals to the frame
   // timestamp.
   LagAreaInFrame first_frame(event_info.finish_timestamp);
   frame_lag_infos_.push_back(first_frame);

   // Reset fields.
   last_reported_time_ = event_info.event_timestamp;
   last_finished_frame_time_ = event_info.event_timestamp;
   last_event_accumulated_delta_ = 0;
   last_rendered_accumulated_delta_ = 0;
   is_begin_ = true;
 }

 void AverageLagTracker::AddScrollUpdateInFrame(const EventInfo& event_info) {
   DCHECK_EQ(event_info.event_type, EventType::ScrollUpdate);

   // Only accept events in nondecreasing order.
   if ((event_info.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_info.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, event_info.event_scroll_delta,
                    event_info.event_timestamp,
                    frame_lag_infos_.front().rendered_accumulated_delta);
     frame_lag_infos_.front().lag_area_no_prediction += LagBetween(
         front_time, back_time, event_info.event_scroll_delta,
         event_info.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() ||
       event_info.finish_timestamp > frame_lag_infos_.back().frame_time) {
     LagAreaInFrame new_frame(event_info.finish_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_LE(last_finished_frame_time_, event_info.event_timestamp);
     DCHECK_LE(event_info.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_info.event_timestamp;

     frame_lag_infos_.front().lag_area +=
         LagBetween(front_time, back_time, event_info.event_scroll_delta,
                    event_info.event_timestamp,
                    frame_lag_infos_.front().rendered_accumulated_delta);

     frame_lag_infos_.front().lag_area_no_prediction += LagBetween(
         front_time, back_time, event_info.event_scroll_delta,
         event_info.event_timestamp,
         frame_lag_infos_.front().rendered_accumulated_delta_no_prediction);
   }
 }

 float AverageLagTracker::LagBetween(base::TimeTicks front_time,
                                     base::TimeTicks back_time,
                                     const float scroll_delta,
                                     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_ +
        (scroll_delta * ((front_time - last_event_timestamp_) /
                         (event_timestamp - last_event_timestamp_)))) -
       rendered_accumulated_delta;

   float back_delta =
       (last_event_accumulated_delta_ +
        scroll_delta * ((back_time - last_event_timestamp_) /
                        (event_timestamp - last_event_timestamp_))) -
       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_GE(frame_lag.lag_area, 0.f);
   DCHECK_GE(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_EQ(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_) >= base::Seconds(1)) {
     const EventType event_type =
         is_begin_ ? EventType::ScrollBegin : EventType::ScrollUpdate;

     const float time_delta =
         (frame_lag.frame_time - last_reported_time_).InMillisecondsF();
     const float scaled_lag_with_prediction = accumulated_lag_ / time_delta;
     const float scaled_lag_no_prediction =
         accumulated_lag_no_prediction_ / time_delta;

     base::UmaHistogramCounts1000(GetAverageLagMetricName(event_type),
                                  scaled_lag_with_prediction);
     base::UmaHistogramCounts1000(
         base::JoinString({GetAverageLagMetricName(event_type), "NoPrediction"},
                          "."),
         scaled_lag_no_prediction);

     const float lag_improvement =
         scaled_lag_no_prediction - scaled_lag_with_prediction;

     // 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 (event_type == EventType::ScrollUpdate) {
       if (lag_improvement >= 0.f) {
         base::UmaHistogramCounts1000(
             base::JoinString(
                 {GetAverageLagMetricName(event_type), "PredictionPositive"},
                 "."),
             lag_improvement);
       } else {
         base::UmaHistogramCounts1000(
             base::JoinString(
                 {GetAverageLagMetricName(event_type), "PredictionNegative"},
                 "."),
             -lag_improvement);
       }

       if (scaled_lag_no_prediction > 0) {
         // How much of the original lag wasn't removed by prediction.
         float remaining_lag_ratio =
             scaled_lag_with_prediction / scaled_lag_no_prediction;

         // Using custom bucket count for high precision on values in (0, 100).
         // With 100 buckets, (0, 100) is mapped into 60 buckets.
         base::UmaHistogramCustomCounts(
             base::JoinString(
                 {GetAverageLagMetricName(event_type), "RemainingLagPercentage"},
                 "."),
             100 * remaining_lag_ratio, 1, 500, 100);
       }
     }
     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 cc
	// Copyright 2019 The Chromium Authors
	// 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_tracker.h"

	#include <algorithm>

	#include "base/metrics/histogram_functions.h"
	#include "base/strings/string_util.h"

	namespace cc {

	AverageLagTracker::AverageLagTracker() = default;
	AverageLagTracker::~AverageLagTracker() = default;

	void AverageLagTracker::AddScrollEventInFrame(const EventInfo& event_info) {
	if (event_info.event_type == EventType::ScrollBegin) {
	AddScrollBeginInFrame(event_info);
	} else if (!last_event_timestamp_.is_null()) {
	AddScrollUpdateInFrame(event_info);
	}

	last_event_timestamp_ = event_info.event_timestamp;
	last_event_accumulated_delta_ += event_info.event_scroll_delta;
	last_rendered_accumulated_delta_ += event_info.predicted_scroll_delta;
	}

	std::string AverageLagTracker::GetAverageLagMetricName(EventType event) const {
	std::string metric_name = "AverageLagPresentation";

	std::string event_name =
	event == EventType::ScrollBegin ? "ScrollBegin" : "ScrollUpdate";

	return base::JoinString(
	{"Event", "Latency", event_name, "Touch", metric_name}, ".");
	}

	void AverageLagTracker::AddScrollBeginInFrame(const EventInfo& event_info) {
	DCHECK_EQ(event_info.event_type, EventType::ScrollBegin);

	// 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_EQ(accumulated_lag_, 0);

	// Create ScrollBegin report, with report time equals to the frame
	// timestamp.
	LagAreaInFrame first_frame(event_info.finish_timestamp);
	frame_lag_infos_.push_back(first_frame);

	// Reset fields.
	last_reported_time_ = event_info.event_timestamp;
	last_finished_frame_time_ = event_info.event_timestamp;
	last_event_accumulated_delta_ = 0;
	last_rendered_accumulated_delta_ = 0;
	is_begin_ = true;
	}

	void AverageLagTracker::AddScrollUpdateInFrame(const EventInfo& event_info) {
	DCHECK_EQ(event_info.event_type, EventType::ScrollUpdate);

	// Only accept events in nondecreasing order.
	if ((event_info.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_info.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, event_info.event_scroll_delta,
	event_info.event_timestamp,
	frame_lag_infos_.front().rendered_accumulated_delta);
	frame_lag_infos_.front().lag_area_no_prediction += LagBetween(
	front_time, back_time, event_info.event_scroll_delta,
	event_info.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() \|\|
	event_info.finish_timestamp > frame_lag_infos_.back().frame_time) {
	LagAreaInFrame new_frame(event_info.finish_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_LE(last_finished_frame_time_, event_info.event_timestamp);
	DCHECK_LE(event_info.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_info.event_timestamp;

	frame_lag_infos_.front().lag_area +=
	LagBetween(front_time, back_time, event_info.event_scroll_delta,
	event_info.event_timestamp,
	frame_lag_infos_.front().rendered_accumulated_delta);

	frame_lag_infos_.front().lag_area_no_prediction += LagBetween(
	front_time, back_time, event_info.event_scroll_delta,
	event_info.event_timestamp,
	frame_lag_infos_.front().rendered_accumulated_delta_no_prediction);
	}
	}

	float AverageLagTracker::LagBetween(base::TimeTicks front_time,
	base::TimeTicks back_time,
	const float scroll_delta,
	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_ +
	(scroll_delta * ((front_time - last_event_timestamp_) /
	(event_timestamp - last_event_timestamp_)))) -
	rendered_accumulated_delta;

	float back_delta =
	(last_event_accumulated_delta_ +
	scroll_delta * ((back_time - last_event_timestamp_) /
	(event_timestamp - last_event_timestamp_))) -
	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_GE(frame_lag.lag_area, 0.f);
	DCHECK_GE(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_EQ(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_) >= base::Seconds(1)) {
	const EventType event_type =
	is_begin_ ? EventType::ScrollBegin : EventType::ScrollUpdate;

	const float time_delta =
	(frame_lag.frame_time - last_reported_time_).InMillisecondsF();
	const float scaled_lag_with_prediction = accumulated_lag_ / time_delta;
	const float scaled_lag_no_prediction =
	accumulated_lag_no_prediction_ / time_delta;

	base::UmaHistogramCounts1000(GetAverageLagMetricName(event_type),
	scaled_lag_with_prediction);
	base::UmaHistogramCounts1000(
	base::JoinString({GetAverageLagMetricName(event_type), "NoPrediction"},
	"."),
	scaled_lag_no_prediction);

	const float lag_improvement =
	scaled_lag_no_prediction - scaled_lag_with_prediction;

	// 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 (event_type == EventType::ScrollUpdate) {
	if (lag_improvement >= 0.f) {
	base::UmaHistogramCounts1000(
	base::JoinString(
	{GetAverageLagMetricName(event_type), "PredictionPositive"},
	"."),
	lag_improvement);
	} else {
	base::UmaHistogramCounts1000(
	base::JoinString(
	{GetAverageLagMetricName(event_type), "PredictionNegative"},
	"."),
	-lag_improvement);
	}

	if (scaled_lag_no_prediction > 0) {
	// How much of the original lag wasn't removed by prediction.
	float remaining_lag_ratio =
	scaled_lag_with_prediction / scaled_lag_no_prediction;

	// Using custom bucket count for high precision on values in (0, 100).
	// With 100 buckets, (0, 100) is mapped into 60 buckets.
	base::UmaHistogramCustomCounts(
	base::JoinString(
	{GetAverageLagMetricName(event_type), "RemainingLagPercentage"},
	"."),
	100 * remaining_lag_ratio, 1, 500, 100);
	}
	}
	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 cc