#include "cc/metrics/compositor_frame_reporting_controller.h"
#include <algorithm>
#include <memory>
#include <optional>
#include <string>
#include <utility>
#include <vector>
#include "base/feature_list.h"
#include "base/rand_util.h"
#include "base/strings/strcat.h"
#include "base/strings/string_number_conversions.h"
#include "base/test/metrics/histogram_tester.h"
#include "base/test/scoped_feature_list.h"
#include "base/test/simple_test_tick_clock.h"
#include "base/test/test_trace_processor.h"
#include "base/time/time.h"
#include "cc/base/features.h"
#include "cc/metrics/event_metrics.h"
#include "cc/metrics/frame_sequence_metrics.h"
#include "cc/metrics/frame_sequence_tracker_collection.h"
#include "cc/scheduler/commit_earlyout_reason.h"
#include "cc/scheduler/scheduler.h"
#include "components/viz/common/frame_timing_details.h"
#include "components/viz/common/quads/compositor_frame_metadata.h"
#include "testing/gmock/include/gmock/gmock.h"
#include "testing/gtest/include/gtest/gtest.h"
#include "ui/events/types/scroll_input_type.h"
namespace cc {
namespace {
using ::testing::Each;
using ::testing::IsEmpty;
using ::testing::NotNull;
using SmoothEffectDrivingThread = FrameInfo::SmoothEffectDrivingThread;
class TestCompositorFrameReportingController
: public CompositorFrameReportingController {
public:
explicit TestCompositorFrameReportingController(
bool is_trees_in_viz_client = false)
: CompositorFrameReportingController(
/*should_report_histograms=*/true,
false,
1,
is_trees_in_viz_client) {}
TestCompositorFrameReportingController(
const TestCompositorFrameReportingController& controller) = delete;
TestCompositorFrameReportingController& operator=(
const TestCompositorFrameReportingController& controller) = delete;
int ActiveReporters() {
int count = 0;
for (int i = 0; i < PipelineStage::kNumPipelineStages; ++i) {
if (ReportersForTesting()[i]) {
++count;
}
}
return count;
}
void ResetReporters() {
for (int i = 0; i < PipelineStage::kNumPipelineStages; ++i) {
ReportersForTesting()[i] = nullptr;
}
}
size_t GetBlockingReportersCount() {
size_t count = 0;
const PipelineStage kStages[] = {
PipelineStage::kBeginImplFrame,
PipelineStage::kBeginMainFrame,
PipelineStage::kCommit,
PipelineStage::kActivate,
};
for (auto stage : kStages) {
auto& reporter = ReportersForTesting()[stage];
if (reporter &&
reporter->partial_update_dependents_size_for_testing() > 0) {
++count;
}
}
return count;
}
size_t GetBlockedReportersCount() {
size_t count = 0;
const PipelineStage kStages[] = {
PipelineStage::kBeginImplFrame,
PipelineStage::kBeginMainFrame,
PipelineStage::kCommit,
PipelineStage::kActivate,
};
for (auto stage : kStages) {
auto& reporter = ReportersForTesting()[stage];
if (reporter)
count += reporter->partial_update_dependents_size_for_testing();
}
return count;
}
size_t GetAdoptedReportersCount() {
size_t count = 0;
const PipelineStage kStages[] = {
PipelineStage::kBeginImplFrame,
PipelineStage::kBeginMainFrame,
PipelineStage::kCommit,
PipelineStage::kActivate,
};
for (auto stage : kStages) {
auto& reporter = ReportersForTesting()[stage];
if (reporter)
count += reporter->owned_partial_update_dependents_size_for_testing();
}
return count;
}
void trees_in_viz_client(bool new_value) {
set_trees_in_viz_client_for_testing(new_value);
}
};
class CompositorFrameReportingControllerTest : public testing::Test {
public:
CompositorFrameReportingControllerTest()
: current_id_(1, 1), tracker_collection_(false) {
test_tick_clock_.SetNowTicks(base::TimeTicks::Now());
reporting_controller_.set_tick_clock(&test_tick_clock_);
args_ = SimulateBeginFrameArgs(current_id_);
reporting_controller_.SetFrameSorter(&frame_sorter_);
reporting_controller_.SetFrameSequenceTrackerCollection(
&tracker_collection_);
}
void SimulateBeginImplFrame() {
IncrementCurrentId();
args_.frame_time = test_tick_clock_.NowTicks();
begin_impl_time_ = AdvanceNowByMs(10);
reporting_controller_.WillBeginImplFrame(args_,
false);
}
void SimulateBeginMainFrame() {
if (!reporting_controller_
.ReportersForTesting()[CompositorFrameReportingController::
PipelineStage::kBeginImplFrame]) {
SimulateBeginImplFrame();
}
CHECK(reporting_controller_
.ReportersForTesting()[CompositorFrameReportingController::
PipelineStage::kBeginImplFrame]);
begin_main_time_ = AdvanceNowByMs(10);
reporting_controller_.WillBeginMainFrame(args_);
begin_main_start_time_ = AdvanceNowByMs(10);
}
void SimulateCommit(std::unique_ptr<BeginMainFrameMetrics> blink_breakdown) {
if (!reporting_controller_
.ReportersForTesting()[CompositorFrameReportingController::
PipelineStage::kBeginMainFrame]) {
SimulateBeginMainFrame();
}
CHECK(reporting_controller_
.ReportersForTesting()[CompositorFrameReportingController::
PipelineStage::kBeginMainFrame]);
reporting_controller_.BeginMainFrameStarted(begin_main_start_time_);
reporting_controller_.NotifyReadyToCommit(std::move(blink_breakdown));
begin_commit_time_ = AdvanceNowByMs(10);
reporting_controller_.WillCommit();
end_commit_time_ = AdvanceNowByMs(10);
reporting_controller_.DidCommit();
}
void SimulateActivate() {
if (!reporting_controller_.ReportersForTesting()
[CompositorFrameReportingController::PipelineStage::kCommit]) {
SimulateCommit(nullptr);
}
CHECK(reporting_controller_.ReportersForTesting()
[CompositorFrameReportingController::PipelineStage::kCommit]);
begin_activation_time_ = AdvanceNowByMs(10);
reporting_controller_.WillActivate();
end_activation_time_ = AdvanceNowByMs(10);
reporting_controller_.DidActivate();
last_activated_id_ = current_id_;
}
void SimulateSubmitCompositorFrame(EventMetricsSet events_metrics) {
if (!reporting_controller_.ReportersForTesting()
[CompositorFrameReportingController::PipelineStage::kActivate]) {
SimulateActivate();
}
CHECK(reporting_controller_.ReportersForTesting()
[CompositorFrameReportingController::PipelineStage::kActivate]);
submit_time_ = AdvanceNowByMs(10);
++current_token_;
SubmitInfo submit_info = {*current_token_, submit_time_};
submit_info.events_metrics = std::move(events_metrics);
reporting_controller_.DidSubmitCompositorFrame(submit_info, current_id_,
last_activated_id_);
}
void SimulatePresentCompositorFrame() {
SimulateSubmitCompositorFrame({});
viz::FrameTimingDetails details = {};
details.presentation_feedback.timestamp = AdvanceNowByMs(10);
reporting_controller_.DidPresentCompositorFrame(*current_token_, details);
}
viz::BeginFrameArgs SimulateBeginFrameArgs(viz::BeginFrameId frame_id) {
args_ = viz::BeginFrameArgs();
args_.frame_id = frame_id;
args_.frame_time = AdvanceNowByMs(10);
args_.interval = base::Milliseconds(16);
current_id_ = frame_id;
return args_;
}
std::unique_ptr<BeginMainFrameMetrics> BuildBlinkBreakdown() {
auto breakdown = std::make_unique<BeginMainFrameMetrics>();
breakdown->handle_input_events = base::Microseconds(10);
breakdown->animate = base::Microseconds(9);
breakdown->style_update = base::Microseconds(8);
breakdown->layout_update = base::Microseconds(7);
breakdown->compositing_inputs = base::Microseconds(6);
breakdown->prepaint = base::Microseconds(5);
breakdown->paint = base::Microseconds(3);
breakdown->composite_commit = base::Microseconds(2);
breakdown->update_layers = base::Microseconds(1);
AdvanceNowByMs(10 + 9 + 8 + 7 + 6 + 5 + 3 + 2 + 1);
return breakdown;
}
viz::FrameTimingDetails BuildVizBreakdown() {
viz::FrameTimingDetails viz_breakdown;
viz_breakdown.received_compositor_frame_timestamp = AdvanceNowByMs(1);
viz_breakdown.draw_start_timestamp = AdvanceNowByMs(2);
viz_breakdown.swap_timings.swap_start = AdvanceNowByMs(3);
viz_breakdown.swap_timings.swap_end = AdvanceNowByMs(4);
viz_breakdown.presentation_feedback.timestamp = AdvanceNowByMs(5);
return viz_breakdown;
}
void IncrementCurrentId() {
current_id_.sequence_number++;
args_.frame_id = current_id_;
}
base::TimeTicks AdvanceNowByMs(int64_t advance_ms) {
test_tick_clock_.Advance(base::Microseconds(advance_ms));
return test_tick_clock_.NowTicks();
}
std::unique_ptr<EventMetrics> SetupEventMetrics(
std::unique_ptr<EventMetrics> metrics) {
if (metrics) {
AdvanceNowByMs(10);
metrics->SetDispatchStageTimestamp(
EventMetrics::DispatchStage::kRendererCompositorStarted);
AdvanceNowByMs(10);
metrics->SetDispatchStageTimestamp(
EventMetrics::DispatchStage::kRendererCompositorFinished);
}
return metrics;
}
std::unique_ptr<EventMetrics> CreateEventMetrics(
ui::EventType type,
std::optional<EventMetrics::TraceId> trace_id) {
const base::TimeTicks event_time = AdvanceNowByMs(10);
const base::TimeTicks arrived_in_browser_main_timestamp = AdvanceNowByMs(3);
AdvanceNowByMs(10);
return SetupEventMetrics(EventMetrics::CreateForTesting(
type, event_time, arrived_in_browser_main_timestamp, &test_tick_clock_,
trace_id));
}
std::unique_ptr<EventMetrics> CreateScrollBeginEventMetrics(
ui::ScrollInputType input_type) {
const base::TimeTicks event_time = AdvanceNowByMs(10);
const base::TimeTicks arrived_in_browser_main_timestamp = AdvanceNowByMs(3);
AdvanceNowByMs(10);
return SetupEventMetrics(ScrollEventMetrics::CreateForTesting(
ui::EventType::kGestureScrollBegin, input_type,
false, event_time, arrived_in_browser_main_timestamp,
&test_tick_clock_));
}
std::unique_ptr<EventMetrics> CreateScrollEndEventMetrics(
ui::ScrollInputType input_type,
bool is_inertial) {
const base::TimeTicks event_time = AdvanceNowByMs(10);
const base::TimeTicks arrived_in_browser_main_timestamp = AdvanceNowByMs(3);
AdvanceNowByMs(10);
std::unique_ptr<EventMetrics> metrics =
SetupEventMetrics(ScrollEventMetrics::CreateForTesting(
ui::EventType::kGestureScrollEnd, input_type, is_inertial,
event_time, arrived_in_browser_main_timestamp, &test_tick_clock_));
metrics->set_caused_frame_update(false);
return metrics;
}
std::unique_ptr<EventMetrics> CreateScrollUpdateEventMetrics(
ui::ScrollInputType input_type,
bool is_inertial,
ScrollUpdateEventMetrics::ScrollUpdateType scroll_update_type,
std::optional<EventMetrics::TraceId> trace_id) {
const base::TimeTicks event_time = AdvanceNowByMs(10);
const base::TimeTicks arrived_in_browser_main_timestamp = AdvanceNowByMs(3);
AdvanceNowByMs(10);
auto scroll_update = ScrollUpdateEventMetrics::CreateForTesting(
ui::EventType::kGestureScrollUpdate, input_type, is_inertial,
scroll_update_type, 10.0f, event_time,
arrived_in_browser_main_timestamp, &test_tick_clock_, trace_id);
scroll_update->set_did_scroll(true);
return SetupEventMetrics(std::move(scroll_update));
}
std::unique_ptr<EventMetrics> CreatePinchEventMetrics(
ui::EventType type,
ui::ScrollInputType input_type) {
const base::TimeTicks event_time = AdvanceNowByMs(10);
AdvanceNowByMs(10);
return SetupEventMetrics(PinchEventMetrics::CreateForTesting(
type, input_type, event_time, &test_tick_clock_));
}
std::vector<base::TimeTicks> GetEventTimestamps(
const EventMetrics::List& events_metrics) {
std::vector<base::TimeTicks> event_times;
event_times.reserve(events_metrics.size());
std::ranges::transform(events_metrics, std::back_inserter(event_times),
[](const auto& event_metrics) {
return event_metrics->GetDispatchStageTimestamp(
EventMetrics::DispatchStage::kGenerated);
});
return event_times;
}
protected:
base::MetricsSubSampler::ScopedAlwaysSampleForTesting no_subsampling_;
base::SimpleTestTickClock test_tick_clock_;
viz::BeginFrameArgs args_;
viz::BeginFrameId current_id_;
viz::BeginFrameId last_activated_id_;
base::TimeTicks begin_impl_time_;
base::TimeTicks begin_main_time_;
base::TimeTicks begin_main_start_time_;
base::TimeTicks begin_commit_time_;
base::TimeTicks end_commit_time_;
base::TimeTicks begin_activation_time_;
base::TimeTicks end_activation_time_;
base::TimeTicks submit_time_;
viz::FrameTokenGenerator current_token_;
FrameSorter frame_sorter_;
FrameSequenceTrackerCollection tracker_collection_;
TestCompositorFrameReportingController reporting_controller_;
::base::test::TracingEnvironment tracing_environment_;
};
TEST_F(CompositorFrameReportingControllerTest, ActiveReporterCounts) {
viz::BeginFrameId current_id_1(1, 1);
viz::BeginFrameArgs args_1 = SimulateBeginFrameArgs(current_id_1);
viz::BeginFrameId current_id_2(1, 2);
viz::BeginFrameArgs args_2 = SimulateBeginFrameArgs(current_id_2);
viz::BeginFrameId current_id_3(1, 3);
viz::BeginFrameArgs args_3 = SimulateBeginFrameArgs(current_id_3);
reporting_controller_.WillBeginImplFrame(args_1,
false);
EXPECT_EQ(1, reporting_controller_.ActiveReporters());
reporting_controller_.OnFinishImplFrame(args_1.frame_id,
true);
reporting_controller_.DidNotProduceFrame(args_1.frame_id,
FrameSkippedReason::kNoDamage);
reporting_controller_.WillBeginImplFrame(args_2,
false);
EXPECT_EQ(1, reporting_controller_.ActiveReporters());
reporting_controller_.OnFinishImplFrame(args_2.frame_id,
true);
reporting_controller_.DidNotProduceFrame(args_2.frame_id,
FrameSkippedReason::kNoDamage);
reporting_controller_.WillBeginMainFrame(args_2);
reporting_controller_.WillBeginImplFrame(args_3,
false);
EXPECT_EQ(2, reporting_controller_.ActiveReporters());
reporting_controller_.NotifyReadyToCommit(nullptr);
reporting_controller_.WillCommit();
reporting_controller_.DidCommit();
EXPECT_EQ(2, reporting_controller_.ActiveReporters());
reporting_controller_.WillBeginMainFrame(args_3);
reporting_controller_.WillActivate();
reporting_controller_.DidActivate();
EXPECT_EQ(2, reporting_controller_.ActiveReporters());
reporting_controller_.NotifyReadyToCommit(nullptr);
reporting_controller_.WillCommit();
reporting_controller_.DidCommit();
reporting_controller_.WillActivate();
reporting_controller_.DidActivate();
EXPECT_EQ(1, reporting_controller_.ActiveReporters());
last_activated_id_ = current_id_3;
SubmitInfo submit_info;
submit_info.time = AdvanceNowByMs(10);
reporting_controller_.DidSubmitCompositorFrame(submit_info, current_id_3,
last_activated_id_);
EXPECT_EQ(0, reporting_controller_.ActiveReporters());
SimulateActivate();
EXPECT_EQ(1, reporting_controller_.ActiveReporters());
SimulateCommit(nullptr);
EXPECT_EQ(2, reporting_controller_.ActiveReporters());
SimulateBeginMainFrame();
EXPECT_EQ(3, reporting_controller_.ActiveReporters());
SimulateBeginImplFrame();
EXPECT_EQ(4, reporting_controller_.ActiveReporters());
reporting_controller_.OnFinishImplFrame(args_.frame_id,
true);
reporting_controller_.DidNotProduceFrame(args_.frame_id,
FrameSkippedReason::kNoDamage);
SimulateBeginImplFrame();
EXPECT_EQ(4, reporting_controller_.ActiveReporters());
}
TEST_F(CompositorFrameReportingControllerTest,
StopRequestingFramesCancelsInFlightFrames) {
base::HistogramTester histogram_tester;
SimulateActivate();
SimulateCommit(nullptr);
reporting_controller_.OnStoppedRequestingBeginFrames();
reporting_controller_.ResetReporters();
histogram_tester.ExpectBucketCount(
"CompositorLatency2.Type",
CompositorFrameReporter::FrameReportType::kDroppedFrame, 0);
}
TEST_F(CompositorFrameReportingControllerTest,
SubmittedFrameHistogramReporting) {
base::HistogramTester histogram_tester;
SimulateActivate();
SimulateCommit(nullptr);
SimulatePresentCompositorFrame();
histogram_tester.ExpectTotalCount(
"CompositorLatency2.BeginImplFrameToSendBeginMainFrame", 1);
histogram_tester.ExpectTotalCount(
"CompositorLatency2.SendBeginMainFrameToCommit", 1);
histogram_tester.ExpectTotalCount("CompositorLatency2.Commit", 1);
histogram_tester.ExpectTotalCount("CompositorLatency2.EndCommitToActivation",
1);
histogram_tester.ExpectTotalCount("CompositorLatency2.Activation", 1);
histogram_tester.ExpectTotalCount(
"CompositorLatency2.EndActivateToSubmitCompositorFrame", 1);
SimulateCommit(nullptr);
histogram_tester.ExpectTotalCount(
"CompositorLatency2.BeginImplFrameToSendBeginMainFrame", 1);
histogram_tester.ExpectTotalCount(
"CompositorLatency2.SendBeginMainFrameToCommit", 1);
histogram_tester.ExpectTotalCount("CompositorLatency2.Commit", 1);
histogram_tester.ExpectTotalCount("CompositorLatency2.EndCommitToActivation",
1);
histogram_tester.ExpectTotalCount("CompositorLatency2.Activation", 1);
histogram_tester.ExpectTotalCount(
"CompositorLatency2.EndActivateToSubmitCompositorFrame", 1);
}
TEST_F(CompositorFrameReportingControllerTest, MainFrameCausedNoDamage) {
base::HistogramTester histogram_tester;
viz::BeginFrameId current_id_1(1, 1);
viz::BeginFrameArgs args_1 = SimulateBeginFrameArgs(current_id_1);
viz::BeginFrameId current_id_2(1, 2);
viz::BeginFrameArgs args_2 = SimulateBeginFrameArgs(current_id_2);
viz::BeginFrameId current_id_3(1, 3);
viz::BeginFrameArgs args_3 = SimulateBeginFrameArgs(current_id_3);
reporting_controller_.WillBeginImplFrame(args_1,
false);
reporting_controller_.WillBeginMainFrame(args_1);
reporting_controller_.BeginMainFrameAborted(
current_id_1, CommitEarlyOutReason::kFinishedNoUpdates);
reporting_controller_.OnFinishImplFrame(current_id_1,
true);
reporting_controller_.DidNotProduceFrame(current_id_1,
FrameSkippedReason::kNoDamage);
reporting_controller_.WillBeginImplFrame(args_2,
false);
reporting_controller_.WillBeginMainFrame(args_2);
reporting_controller_.OnFinishImplFrame(current_id_2,
true);
reporting_controller_.BeginMainFrameAborted(
current_id_2, CommitEarlyOutReason::kFinishedNoUpdates);
reporting_controller_.DidNotProduceFrame(current_id_2,
FrameSkippedReason::kNoDamage);
reporting_controller_.WillBeginImplFrame(args_3,
false);
reporting_controller_.WillBeginMainFrame(args_3);
histogram_tester.ExpectTotalCount(
"CompositorLatency2.DroppedFrame.BeginImplFrameToSendBeginMainFrame", 0);
histogram_tester.ExpectTotalCount(
"CompositorLatency2.DroppedFrame.SendBeginMainFrameToCommit", 0);
}
TEST_F(CompositorFrameReportingControllerTest, DidNotProduceFrame) {
base::HistogramTester histogram_tester;
viz::BeginFrameId current_id_1(1, 1);
viz::BeginFrameArgs args_1 = SimulateBeginFrameArgs(current_id_1);
viz::BeginFrameId current_id_2(1, 2);
viz::BeginFrameArgs args_2 = SimulateBeginFrameArgs(current_id_2);
reporting_controller_.WillBeginImplFrame(args_1,
false);
reporting_controller_.WillBeginMainFrame(args_1);
reporting_controller_.OnFinishImplFrame(current_id_1,
true);
reporting_controller_.DidNotProduceFrame(current_id_1,
FrameSkippedReason::kNoDamage);
reporting_controller_.WillBeginImplFrame(args_2,
false);
reporting_controller_.OnFinishImplFrame(current_id_2,
true);
reporting_controller_.NotifyReadyToCommit(nullptr);
reporting_controller_.WillCommit();
reporting_controller_.DidCommit();
reporting_controller_.WillActivate();
reporting_controller_.DidActivate();
SubmitInfo submit_info = {1u, AdvanceNowByMs(10)};
reporting_controller_.DidSubmitCompositorFrame(submit_info, current_id_2,
current_id_1);
viz::FrameTimingDetails details = {};
reporting_controller_.DidPresentCompositorFrame(1, details);
histogram_tester.ExpectTotalCount(
"CompositorLatency2.DroppedFrame.BeginImplFrameToSendBeginMainFrame", 0);
histogram_tester.ExpectTotalCount(
"CompositorLatency2.DroppedFrame.SendBeginMainFrameToCommit", 0);
histogram_tester.ExpectTotalCount(
"CompositorLatency2.BeginImplFrameToSendBeginMainFrame", 2);
histogram_tester.ExpectTotalCount(
"CompositorLatency2.SendBeginMainFrameToCommit", 1);
histogram_tester.ExpectTotalCount("CompositorLatency2.Commit", 1);
histogram_tester.ExpectTotalCount("CompositorLatency2.EndCommitToActivation",
1);
histogram_tester.ExpectTotalCount("CompositorLatency2.Activation", 1);
histogram_tester.ExpectTotalCount(
"CompositorLatency2.EndActivateToSubmitCompositorFrame", 2);
histogram_tester.ExpectTotalCount(
"CompositorLatency2.SubmitCompositorFrameToPresentationCompositorFrame",
2);
}
TEST_F(CompositorFrameReportingControllerTest, MainFrameAborted) {
base::HistogramTester histogram_tester;
reporting_controller_.WillBeginImplFrame(args_, false);
reporting_controller_.WillBeginMainFrame(args_);
reporting_controller_.BeginMainFrameAborted(
current_id_, CommitEarlyOutReason::kFinishedNoUpdates);
reporting_controller_.OnFinishImplFrame(current_id_,
true);
SubmitInfo submit_info = {1u, AdvanceNowByMs(10)};
reporting_controller_.DidSubmitCompositorFrame(submit_info, current_id_,
last_activated_id_);
viz::FrameTimingDetails details = {};
reporting_controller_.DidPresentCompositorFrame(1, details);
histogram_tester.ExpectTotalCount(
"CompositorLatency2.BeginImplFrameToSendBeginMainFrame", 1);
histogram_tester.ExpectTotalCount(
"CompositorLatency2.SendBeginMainFrameToCommit", 1);
histogram_tester.ExpectTotalCount("CompositorLatency2.Commit", 0);
histogram_tester.ExpectTotalCount("CompositorLatency2.Activation", 0);
histogram_tester.ExpectTotalCount(
"CompositorLatency2.EndActivateToSubmitCompositorFrame", 1);
histogram_tester.ExpectTotalCount(
"CompositorLatency2.SubmitCompositorFrameToPresentationCompositorFrame",
1);
}
TEST_F(CompositorFrameReportingControllerTest, MainFrameAborted2) {
base::HistogramTester histogram_tester;
viz::BeginFrameId current_id_1(1, 1);
viz::BeginFrameArgs args_1 = SimulateBeginFrameArgs(current_id_1);
viz::BeginFrameId current_id_2(1, 2);
viz::BeginFrameArgs args_2 = SimulateBeginFrameArgs(current_id_2);
viz::BeginFrameId current_id_3(1, 3);
viz::BeginFrameArgs args_3 = SimulateBeginFrameArgs(current_id_3);
reporting_controller_.WillBeginImplFrame(args_1,
false);
reporting_controller_.OnFinishImplFrame(current_id_1,
true);
reporting_controller_.WillBeginMainFrame(args_1);
reporting_controller_.NotifyReadyToCommit(nullptr);
reporting_controller_.WillCommit();
reporting_controller_.DidCommit();
reporting_controller_.WillActivate();
reporting_controller_.DidActivate();
reporting_controller_.WillBeginImplFrame(args_2,
false);
reporting_controller_.WillBeginMainFrame(args_2);
reporting_controller_.OnFinishImplFrame(current_id_2,
true);
reporting_controller_.BeginMainFrameAborted(
current_id_2, CommitEarlyOutReason::kFinishedNoUpdates);
SubmitInfo submit_info = {1u, AdvanceNowByMs(10)};
reporting_controller_.DidSubmitCompositorFrame(submit_info, current_id_2,
current_id_1);
viz::FrameTimingDetails details = {};
reporting_controller_.DidPresentCompositorFrame(1, details);
histogram_tester.ExpectTotalCount(
"CompositorLatency2.DroppedFrame.BeginImplFrameToSendBeginMainFrame", 0);
histogram_tester.ExpectTotalCount(
"CompositorLatency2.BeginImplFrameToSendBeginMainFrame", 2);
histogram_tester.ExpectTotalCount(
"CompositorLatency2.SendBeginMainFrameToCommit", 2);
histogram_tester.ExpectTotalCount("CompositorLatency2.Commit", 1);
histogram_tester.ExpectTotalCount("CompositorLatency2.EndCommitToActivation",
1);
histogram_tester.ExpectTotalCount("CompositorLatency2.Activation", 1);
histogram_tester.ExpectTotalCount(
"CompositorLatency2.EndActivateToSubmitCompositorFrame", 2);
histogram_tester.ExpectTotalCount(
"CompositorLatency2.SubmitCompositorFrameToPresentationCompositorFrame",
2);
SubmitInfo submit_info2 = {2u, AdvanceNowByMs(10)};
reporting_controller_.DidSubmitCompositorFrame(submit_info2, current_id_2,
current_id_1);
reporting_controller_.DidPresentCompositorFrame(2, details);
histogram_tester.ExpectTotalCount(
"CompositorLatency2.DroppedFrame.BeginImplFrameToSendBeginMainFrame", 0);
histogram_tester.ExpectTotalCount(
"CompositorLatency2.BeginImplFrameToSendBeginMainFrame", 2);
histogram_tester.ExpectTotalCount(
"CompositorLatency2.SendBeginMainFrameToCommit", 2);
histogram_tester.ExpectTotalCount("CompositorLatency2.Commit", 1);
histogram_tester.ExpectTotalCount("CompositorLatency2.EndCommitToActivation",
1);
histogram_tester.ExpectTotalCount("CompositorLatency2.Activation", 1);
histogram_tester.ExpectTotalCount(
"CompositorLatency2.EndActivateToSubmitCompositorFrame", 2);
histogram_tester.ExpectTotalCount(
"CompositorLatency2.SubmitCompositorFrameToPresentationCompositorFrame",
2);
reporting_controller_.WillBeginImplFrame(args_3,
false);
reporting_controller_.OnFinishImplFrame(current_id_3,
true);
SubmitInfo submit_info3 = {3u, AdvanceNowByMs(10)};
reporting_controller_.DidSubmitCompositorFrame(submit_info3, current_id_3,
current_id_1);
reporting_controller_.DidPresentCompositorFrame(3, details);
histogram_tester.ExpectTotalCount(
"CompositorLatency2.DroppedFrame.BeginImplFrameToSendBeginMainFrame", 0);
histogram_tester.ExpectTotalCount(
"CompositorLatency2.BeginImplFrameToSendBeginMainFrame", 3);
histogram_tester.ExpectTotalCount(
"CompositorLatency2.SendBeginMainFrameToCommit", 2);
histogram_tester.ExpectTotalCount("CompositorLatency2.Commit", 1);
histogram_tester.ExpectTotalCount("CompositorLatency2.EndCommitToActivation",
1);
histogram_tester.ExpectTotalCount("CompositorLatency2.Activation", 1);
histogram_tester.ExpectTotalCount(
"CompositorLatency2.EndActivateToSubmitCompositorFrame", 3);
histogram_tester.ExpectTotalCount(
"CompositorLatency2.SubmitCompositorFrameToPresentationCompositorFrame",
3);
}
TEST_F(CompositorFrameReportingControllerTest, LongMainFrame) {
base::HistogramTester histogram_tester;
viz::BeginFrameId current_id_1(1, 1);
viz::BeginFrameArgs args_1 = SimulateBeginFrameArgs(current_id_1);
viz::BeginFrameId current_id_2(1, 2);
viz::BeginFrameArgs args_2 = SimulateBeginFrameArgs(current_id_2);
viz::BeginFrameId current_id_3(1, 3);
viz::BeginFrameArgs args_3 = SimulateBeginFrameArgs(current_id_3);
viz::FrameTimingDetails details = {};
reporting_controller_.WillBeginImplFrame(args_1,
false);
reporting_controller_.OnFinishImplFrame(current_id_1,
true);
reporting_controller_.WillBeginMainFrame(args_1);
reporting_controller_.NotifyReadyToCommit(nullptr);
reporting_controller_.WillCommit();
reporting_controller_.DidCommit();
reporting_controller_.WillActivate();
reporting_controller_.DidActivate();
SubmitInfo submit_info = {1u, AdvanceNowByMs(10)};
submit_info.normalized_invalidated_area = 10;
reporting_controller_.DidSubmitCompositorFrame(submit_info, current_id_1,
current_id_1);
reporting_controller_.DidPresentCompositorFrame(1, details);
histogram_tester.ExpectTotalCount(
"Graphics.Paint.UI.NormalizedInvalidatedArea", 1);
histogram_tester.ExpectTotalCount(
"CompositorLatency2.BeginImplFrameToSendBeginMainFrame", 1);
histogram_tester.ExpectTotalCount(
"CompositorLatency2.SendBeginMainFrameToCommit", 1);
histogram_tester.ExpectTotalCount("CompositorLatency2.Commit", 1);
histogram_tester.ExpectTotalCount("CompositorLatency2.EndCommitToActivation",
1);
histogram_tester.ExpectTotalCount("CompositorLatency2.Activation", 1);
histogram_tester.ExpectTotalCount(
"CompositorLatency2.EndActivateToSubmitCompositorFrame", 1);
histogram_tester.ExpectTotalCount(
"CompositorLatency2.SubmitCompositorFrameToPresentationCompositorFrame",
1);
reporting_controller_.WillBeginImplFrame(args_2,
false);
reporting_controller_.WillBeginMainFrame(args_2);
reporting_controller_.OnFinishImplFrame(current_id_2,
true);
SubmitInfo submit_info2 = {2u, AdvanceNowByMs(10)};
submit_info2.normalized_invalidated_area = 10;
reporting_controller_.DidSubmitCompositorFrame(submit_info2, current_id_2,
current_id_1);
reporting_controller_.DidPresentCompositorFrame(2, details);
histogram_tester.ExpectTotalCount(
"Graphics.Paint.UI.NormalizedInvalidatedArea", 1);
histogram_tester.ExpectTotalCount(
"CompositorLatency2.BeginImplFrameToSendBeginMainFrame", 1);
histogram_tester.ExpectTotalCount(
"CompositorLatency2.SendBeginMainFrameToCommit", 1);
histogram_tester.ExpectTotalCount("CompositorLatency2.Commit", 1);
histogram_tester.ExpectTotalCount("CompositorLatency2.EndCommitToActivation",
1);
histogram_tester.ExpectTotalCount("CompositorLatency2.Activation", 1);
histogram_tester.ExpectTotalCount(
"CompositorLatency2.EndActivateToSubmitCompositorFrame", 1);
histogram_tester.ExpectTotalCount(
"CompositorLatency2.SubmitCompositorFrameToPresentationCompositorFrame",
1);
reporting_controller_.WillBeginImplFrame(args_3,
false);
reporting_controller_.OnFinishImplFrame(current_id_3,
true);
reporting_controller_.NotifyReadyToCommit(nullptr);
reporting_controller_.WillCommit();
reporting_controller_.DidCommit();
reporting_controller_.WillActivate();
reporting_controller_.DidActivate();
SubmitInfo submit_info3 = {3u, AdvanceNowByMs(10)};
submit_info3.normalized_invalidated_area = 10;
reporting_controller_.DidSubmitCompositorFrame(submit_info3, current_id_3,
current_id_2);
reporting_controller_.DidPresentCompositorFrame(3, details);
histogram_tester.ExpectTotalCount(
"Graphics.Paint.UI.NormalizedInvalidatedArea", 3);
histogram_tester.ExpectTotalCount(
"CompositorLatency2.BeginImplFrameToSendBeginMainFrame", 4);
histogram_tester.ExpectTotalCount(
"CompositorLatency2.SendBeginMainFrameToCommit", 2);
histogram_tester.ExpectTotalCount("CompositorLatency2.Commit", 2);
histogram_tester.ExpectTotalCount("CompositorLatency2.EndCommitToActivation",
2);
histogram_tester.ExpectTotalCount("CompositorLatency2.Activation", 2);
histogram_tester.ExpectTotalCount(
"CompositorLatency2.EndActivateToSubmitCompositorFrame", 4);
histogram_tester.ExpectTotalCount(
"CompositorLatency2.SubmitCompositorFrameToPresentationCompositorFrame",
4);
}
TEST_F(CompositorFrameReportingControllerTest, LongMainFrame2) {
base::HistogramTester histogram_tester;
viz::BeginFrameId current_id_1(1, 1);
viz::BeginFrameArgs args_1 = SimulateBeginFrameArgs(current_id_1);
viz::BeginFrameId current_id_2(1, 2);
viz::BeginFrameArgs args_2 = SimulateBeginFrameArgs(current_id_2);
viz::FrameTimingDetails details = {};
reporting_controller_.WillBeginImplFrame(args_1,
false);
reporting_controller_.OnFinishImplFrame(current_id_1,
true);
reporting_controller_.WillBeginMainFrame(args_1);
reporting_controller_.NotifyReadyToCommit(nullptr);
reporting_controller_.WillCommit();
reporting_controller_.DidCommit();
reporting_controller_.WillActivate();
reporting_controller_.DidActivate();
SubmitInfo submit_info = {1u, AdvanceNowByMs(10)};
submit_info.normalized_invalidated_area = 10;
reporting_controller_.DidSubmitCompositorFrame(submit_info, current_id_1,
current_id_1);
reporting_controller_.DidPresentCompositorFrame(1, details);
histogram_tester.ExpectTotalCount(
"Graphics.Paint.UI.NormalizedInvalidatedArea", 1);
histogram_tester.ExpectTotalCount(
"CompositorLatency2.BeginImplFrameToSendBeginMainFrame", 1);
histogram_tester.ExpectTotalCount(
"CompositorLatency2.SendBeginMainFrameToCommit", 1);
histogram_tester.ExpectTotalCount("CompositorLatency2.Commit", 1);
histogram_tester.ExpectTotalCount("CompositorLatency2.EndCommitToActivation",
1);
histogram_tester.ExpectTotalCount("CompositorLatency2.Activation", 1);
histogram_tester.ExpectTotalCount(
"CompositorLatency2.EndActivateToSubmitCompositorFrame", 1);
histogram_tester.ExpectTotalCount(
"CompositorLatency2.SubmitCompositorFrameToPresentationCompositorFrame",
1);
reporting_controller_.WillBeginImplFrame(args_2,
false);
reporting_controller_.WillBeginMainFrame(args_2);
reporting_controller_.NotifyReadyToCommit(nullptr);
reporting_controller_.WillCommit();
reporting_controller_.DidCommit();
reporting_controller_.OnFinishImplFrame(current_id_2,
true);
SubmitInfo submit_info2 = {2u, AdvanceNowByMs(10)};
submit_info2.normalized_invalidated_area = 10;
reporting_controller_.DidSubmitCompositorFrame(submit_info2, current_id_2,
current_id_1);
reporting_controller_.DidPresentCompositorFrame(2, details);
histogram_tester.ExpectTotalCount(
"Graphics.Paint.UI.NormalizedInvalidatedArea", 1);
histogram_tester.ExpectTotalCount(
"CompositorLatency2.BeginImplFrameToSendBeginMainFrame", 1);
histogram_tester.ExpectTotalCount(
"CompositorLatency2.SendBeginMainFrameToCommit", 1);
histogram_tester.ExpectTotalCount("CompositorLatency2.Commit", 1);
histogram_tester.ExpectTotalCount("CompositorLatency2.EndCommitToActivation",
1);
histogram_tester.ExpectTotalCount("CompositorLatency2.Activation", 1);
histogram_tester.ExpectTotalCount(
"CompositorLatency2.EndActivateToSubmitCompositorFrame", 1);
histogram_tester.ExpectTotalCount(
"CompositorLatency2.SubmitCompositorFrameToPresentationCompositorFrame",
1);
viz::BeginFrameId current_id_3(1, 3);
viz::BeginFrameArgs args_3 = SimulateBeginFrameArgs(current_id_3);
reporting_controller_.WillActivate();
reporting_controller_.DidActivate();
reporting_controller_.WillBeginImplFrame(args_3,
false);
reporting_controller_.OnFinishImplFrame(current_id_3,
true);
SubmitInfo submit_info3 = {3u, AdvanceNowByMs(10)};
submit_info3.normalized_invalidated_area = 10;
reporting_controller_.DidSubmitCompositorFrame(submit_info3, current_id_3,
current_id_2);
reporting_controller_.DidPresentCompositorFrame(3, details);
histogram_tester.ExpectTotalCount(
"Graphics.Paint.UI.NormalizedInvalidatedArea", 3);
histogram_tester.ExpectTotalCount(
"CompositorLatency2.BeginImplFrameToSendBeginMainFrame", 4);
histogram_tester.ExpectTotalCount(
"CompositorLatency2.SendBeginMainFrameToCommit", 2);
histogram_tester.ExpectTotalCount("CompositorLatency2.Commit", 2);
histogram_tester.ExpectTotalCount("CompositorLatency2.EndCommitToActivation",
2);
histogram_tester.ExpectTotalCount("CompositorLatency2.Activation", 2);
histogram_tester.ExpectTotalCount(
"CompositorLatency2.EndActivateToSubmitCompositorFrame", 4);
histogram_tester.ExpectTotalCount(
"CompositorLatency2.SubmitCompositorFrameToPresentationCompositorFrame",
4);
}
TEST_F(CompositorFrameReportingControllerTest, BlinkBreakdown) {
base::HistogramTester histogram_tester;
std::unique_ptr<BeginMainFrameMetrics> blink_breakdown =
BuildBlinkBreakdown();
SimulateActivate();
SimulateCommit(std::move(blink_breakdown));
SimulatePresentCompositorFrame();
histogram_tester.ExpectTotalCount(
"CompositorLatency2.SendBeginMainFrameToCommit", 1);
histogram_tester.ExpectUniqueSample(
"CompositorLatency2.SendBeginMainFrameToCommit.HandleInputEvents",
base::Microseconds(10).InMilliseconds(), 1);
histogram_tester.ExpectUniqueSample(
"CompositorLatency2.SendBeginMainFrameToCommit.Animate",
base::Microseconds(9).InMilliseconds(), 1);
histogram_tester.ExpectUniqueSample(
"CompositorLatency2.SendBeginMainFrameToCommit.StyleUpdate",
base::Microseconds(8).InMilliseconds(), 1);
histogram_tester.ExpectUniqueSample(
"CompositorLatency2.SendBeginMainFrameToCommit.LayoutUpdate",
base::Microseconds(7).InMilliseconds(), 1);
histogram_tester.ExpectUniqueSample(
"CompositorLatency2.SendBeginMainFrameToCommit.CompositingInputs",
base::Microseconds(6).InMilliseconds(), 1);
histogram_tester.ExpectUniqueSample(
"CompositorLatency2.SendBeginMainFrameToCommit.Prepaint",
base::Microseconds(5).InMilliseconds(), 1);
histogram_tester.ExpectUniqueSample(
"CompositorLatency2.SendBeginMainFrameToCommit.Paint",
base::Microseconds(3).InMilliseconds(), 1);
histogram_tester.ExpectUniqueSample(
"CompositorLatency2.SendBeginMainFrameToCommit.CompositeCommit",
base::Microseconds(2).InMilliseconds(), 1);
histogram_tester.ExpectUniqueSample(
"CompositorLatency2.SendBeginMainFrameToCommit.UpdateLayers",
base::Microseconds(1).InMilliseconds(), 1);
histogram_tester.ExpectTotalCount(
"CompositorLatency2.SendBeginMainFrameToCommit.BeginMainSentToStarted",
1);
}
TEST_F(CompositorFrameReportingControllerTest, VizBreakdown) {
if (base::FeatureList::IsEnabled(features::kTreesInViz)) {
return;
}
base::HistogramTester histogram_tester;
SimulateSubmitCompositorFrame({});
viz::FrameTimingDetails viz_details = BuildVizBreakdown();
reporting_controller_.DidPresentCompositorFrame(*current_token_, viz_details);
histogram_tester.ExpectUniqueSample(
"CompositorLatency2.EndActivateToSubmitCompositorFrame", 10, 1);
histogram_tester.ExpectUniqueSample(
"CompositorLatency2.SubmitCompositorFrameToPresentationCompositorFrame."
"SubmitToReceiveCompositorFrame",
1, 1);
histogram_tester.ExpectUniqueSample(
"CompositorLatency2.SubmitCompositorFrameToPresentationCompositorFrame."
"ReceivedCompositorFrameToStartDraw",
2, 1);
histogram_tester.ExpectUniqueSample(
"CompositorLatency2.SubmitCompositorFrameToPresentationCompositorFrame."
"StartDrawToSwapStart",
3, 1);
histogram_tester.ExpectUniqueSample(
"CompositorLatency2.SubmitCompositorFrameToPresentationCompositorFrame."
"SwapStartToSwapEnd",
4, 1);
histogram_tester.ExpectUniqueSample(
"CompositorLatency2.SubmitCompositorFrameToPresentationCompositorFrame."
"SwapEndToPresentationCompositorFrame",
5, 1);
histogram_tester.ExpectUniqueSample(
"CompositorLatency2.SubmitCompositorFrameToPresentationCompositorFrame",
1 + 2 + 3 + 4 + 5, 1);
}
class TreesInVizClientCompositorFrameReportingControllerTest
: public CompositorFrameReportingControllerTest {
public:
TreesInVizClientCompositorFrameReportingControllerTest() {
reporting_controller_.trees_in_viz_client(true);
scoped_feature_list_.InitAndEnableFeature(features::kTreesInViz);
}
void SimulateSubmitCompositorFrameWithTreesInVizTimingDetails(
EventMetricsSet events_metrics) {
if (!reporting_controller_.ReportersForTesting()
[CompositorFrameReportingController::PipelineStage::kActivate]) {
CompositorFrameReportingControllerTest::SimulateActivate();
}
CHECK(reporting_controller_.ReportersForTesting()
[CompositorFrameReportingController::PipelineStage::kActivate]);
submit_time_ = AdvanceNowByMs(7);
++current_token_;
SubmitInfo submit_info = {*current_token_, submit_time_};
submit_info.events_metrics = std::move(events_metrics);
submit_info.trees_in_viz_submit_time = AdvanceNowByMs(11);
reporting_controller_.DidSubmitCompositorFrame(submit_info, current_id_,
last_activated_id_);
}
void SimulatePresentCompositorFrameWithTreesInVizTimingDetails() {
SimulateSubmitCompositorFrameWithTreesInVizTimingDetails({});
viz::FrameTimingDetails details = {};
details.start_update_display_tree =
AdvanceNowByMs(35);
details.start_prepare_to_draw = AdvanceNowByMs(2);
details.start_draw_layers = AdvanceNowByMs(3);
details.submit_compositor_frame = AdvanceNowByMs(5);
details.received_compositor_frame_timestamp = AdvanceNowByMs(6);
details.draw_start_timestamp = AdvanceNowByMs(7);
details.swap_timings.swap_start = AdvanceNowByMs(8);
details.swap_timings.swap_end = AdvanceNowByMs(9);
details.presentation_feedback.timestamp = AdvanceNowByMs(10);
reporting_controller_.DidPresentCompositorFrame(*current_token_, details);
}
protected:
base::test::ScopedFeatureList scoped_feature_list_;
};
TEST_F(TreesInVizClientCompositorFrameReportingControllerTest,
ValidateTreesInVizAbortedFrame) {
reporting_controller_.WillBeginImplFrame(args_, false);
reporting_controller_.WillBeginMainFrame(args_);
SubmitInfo submit_info = {1u, AdvanceNowByMs(10)};
submit_info.trees_in_viz_submit_time = AdvanceNowByMs(13);
reporting_controller_.BeginMainFrameAborted(
current_id_, CommitEarlyOutReason::kFinishedNoUpdates);
reporting_controller_.DidSubmitCompositorFrame(submit_info, current_id_,
last_activated_id_);
}
TEST_F(TreesInVizClientCompositorFrameReportingControllerTest,
ValidateTreesInVizBreakdown) {
base::HistogramTester histogram_tester;
SimulatePresentCompositorFrameWithTreesInVizTimingDetails();
histogram_tester.ExpectUniqueSample(
"CompositorLatency2.EndActivateToSubmitUpdateDisplayTree."
"EndActivateToDrawLayers",
7, 1);
histogram_tester.ExpectUniqueSample(
"CompositorLatency2.EndActivateToSubmitUpdateDisplayTree."
"DrawLayersToSubmitUpdateDisplayTree",
11, 1);
histogram_tester.ExpectUniqueSample(
"CompositorLatency2.SubmitUpdateDisplayTreeToPresentationCompositorFrame."
"SendUpdateDisplayTreeToReceiveUpdateDisplayTree",
35, 1);
histogram_tester.ExpectUniqueSample(
"CompositorLatency2.SubmitUpdateDisplayTreeToPresentationCompositorFrame."
"ReceiveUpdateDisplayTreeToStartPrepareToDraw",
2, 1);
histogram_tester.ExpectUniqueSample(
"CompositorLatency2.SubmitUpdateDisplayTreeToPresentationCompositorFrame."
"StartPrepareToDrawToStartDrawLayers",
3, 1);
histogram_tester.ExpectUniqueSample(
"CompositorLatency2.SubmitUpdateDisplayTreeToPresentationCompositorFrame."
"StartDrawLayersToSubmitCompositorFrame",
5, 1);
histogram_tester.ExpectUniqueSample(
"CompositorLatency2.SubmitUpdateDisplayTreeToPresentationCompositorFrame."
"SubmitToReceiveCompositorFrame",
6, 1);
histogram_tester.ExpectUniqueSample(
"CompositorLatency2.SubmitUpdateDisplayTreeToPresentationCompositorFrame."
"ReceivedCompositorFrameToStartDraw",
7, 1);
histogram_tester.ExpectUniqueSample(
"CompositorLatency2.SubmitUpdateDisplayTreeToPresentationCompositorFrame."
"StartDrawToSwapStart",
8, 1);
histogram_tester.ExpectUniqueSample(
"CompositorLatency2.SubmitUpdateDisplayTreeToPresentationCompositorFrame."
"SwapStartToSwapEnd",
9, 1);
histogram_tester.ExpectUniqueSample(
"CompositorLatency2.SubmitUpdateDisplayTreeToPresentationCompositorFrame."
"SwapEndToPresentationCompositorFrame",
10, 1);
histogram_tester.ExpectUniqueSample(
"CompositorLatency2.EndActivateToSubmitUpdateDisplayTree", 7 + 11, 1);
histogram_tester.ExpectUniqueSample(
"CompositorLatency2.SubmitUpdateDisplayTreeToPresentationCompositorFrame",
35 + 2 + 3 + 5 + 6 + 7 + 8 + 9 + 10, 1);
}
TEST_F(TreesInVizClientCompositorFrameReportingControllerTest,
EmitBothBranchesOfHistograms) {
base::HistogramTester histogram_tester;
SimulatePresentCompositorFrameWithTreesInVizTimingDetails();
reporting_controller_.trees_in_viz_client(false);
SimulatePresentCompositorFrame();
}
TEST_F(CompositorFrameReportingControllerTest, ReportingMissedDeadlineFrame1) {
base::HistogramTester histogram_tester;
reporting_controller_.WillBeginImplFrame(args_, false);
reporting_controller_.OnFinishImplFrame(current_id_,
true);
reporting_controller_.WillBeginMainFrame(args_);
reporting_controller_.NotifyReadyToCommit(nullptr);
reporting_controller_.WillCommit();
reporting_controller_.DidCommit();
reporting_controller_.WillActivate();
reporting_controller_.DidActivate();
SubmitInfo submit_info = {1u, AdvanceNowByMs(10)};
reporting_controller_.DidSubmitCompositorFrame(submit_info, current_id_,
current_id_);
viz::FrameTimingDetails details = {};
details.presentation_feedback.timestamp =
args_.frame_time + args_.interval * 1.5 - base::Microseconds(100);
reporting_controller_.DidPresentCompositorFrame(1, details);
histogram_tester.ExpectTotalCount(
"CompositorLatency2.BeginImplFrameToSendBeginMainFrame", 1);
histogram_tester.ExpectTotalCount("CompositorLatency2.TotalLatency", 1);
}
TEST_F(CompositorFrameReportingControllerTest, ReportingMissedDeadlineFrame2) {
base::HistogramTester histogram_tester;
reporting_controller_.WillBeginImplFrame(args_, false);
reporting_controller_.OnFinishImplFrame(current_id_,
true);
reporting_controller_.WillBeginMainFrame(args_);
reporting_controller_.NotifyReadyToCommit(nullptr);
reporting_controller_.WillCommit();
reporting_controller_.DidCommit();
reporting_controller_.WillActivate();
reporting_controller_.DidActivate();
SubmitInfo submit_info = {1u, AdvanceNowByMs(10)};
reporting_controller_.DidSubmitCompositorFrame(submit_info, current_id_,
current_id_);
viz::FrameTimingDetails details = {};
details.presentation_feedback.timestamp =
args_.frame_time + args_.interval * 1.5 + base::Microseconds(100);
reporting_controller_.DidPresentCompositorFrame(1, details);
histogram_tester.ExpectTotalCount(
"CompositorLatency2.BeginImplFrameToSendBeginMainFrame", 1);
histogram_tester.ExpectTotalCount("CompositorLatency2.TotalLatency", 1);
}
TEST_F(CompositorFrameReportingControllerTest, LongCompositorAnimation) {
base::HistogramTester histogram_tester;
SimulatePresentCompositorFrame();
reporting_controller_.WillBeginImplFrame(args_, false);
reporting_controller_.OnFinishImplFrame(current_id_,
true);
SubmitInfo submit_info = {1u, AdvanceNowByMs(10)};
reporting_controller_.DidSubmitCompositorFrame(submit_info, current_id_,
last_activated_id_);
viz::FrameTimingDetails details = {};
reporting_controller_.DidPresentCompositorFrame(*current_token_, details);
IncrementCurrentId();
reporting_controller_.WillBeginImplFrame(args_, false);
reporting_controller_.OnFinishImplFrame(current_id_,
true);
reporting_controller_.DidNotProduceFrame(args_.frame_id,
FrameSkippedReason::kDrawThrottled);
IncrementCurrentId();
reporting_controller_.WillBeginImplFrame(args_, false);
reporting_controller_.OnFinishImplFrame(current_id_,
true);
EXPECT_EQ(3u, frame_sorter_.total_frames());
EXPECT_EQ(1u, frame_sorter_.total_dropped());
}
TEST_F(CompositorFrameReportingControllerTest,
EventLatencyTotalForPresentedFrameReported) {
base::HistogramTester histogram_tester;
std::unique_ptr<EventMetrics> event_metrics_ptrs[] = {
CreateEventMetrics(ui::EventType::kTouchPressed, std::nullopt),
CreateEventMetrics(ui::EventType::kTouchMoved, std::nullopt),
CreateEventMetrics(ui::EventType::kTouchMoved, std::nullopt),
};
EXPECT_THAT(event_metrics_ptrs, Each(NotNull()));
EventMetrics::List events_metrics(
std::make_move_iterator(std::begin(event_metrics_ptrs)),
std::make_move_iterator(std::end(event_metrics_ptrs)));
std::vector<base::TimeTicks> event_times = GetEventTimestamps(events_metrics);
SimulateSubmitCompositorFrame({std::move(events_metrics), {}, {}});
const base::TimeTicks presentation_time = AdvanceNowByMs(10);
viz::FrameTimingDetails details;
details.presentation_feedback.timestamp = presentation_time;
reporting_controller_.DidPresentCompositorFrame(*current_token_, details);
struct {
const char* name;
const base::HistogramBase::Count32 count;
} expected_counts[] = {
{"EventLatency.TouchPressed.TotalLatency", 1},
{"EventLatency.TouchMoved.TotalLatency", 2},
{"EventLatency.TotalLatency", 3},
};
for (const auto& expected_count : expected_counts) {
histogram_tester.ExpectTotalCount(expected_count.name,
expected_count.count);
}
struct {
const char* name;
const base::HistogramBase::Sample32 latency_ms;
} expected_latencies[] = {
{"EventLatency.TouchPressed.TotalLatency",
static_cast<base::HistogramBase::Sample32>(
(presentation_time - event_times[0]).InMicroseconds())},
{"EventLatency.TouchMoved.TotalLatency",
static_cast<base::HistogramBase::Sample32>(
(presentation_time - event_times[1]).InMicroseconds())},
{"EventLatency.TouchMoved.TotalLatency",
static_cast<base::HistogramBase::Sample32>(
(presentation_time - event_times[2]).InMicroseconds())},
{"EventLatency.TotalLatency",
static_cast<base::HistogramBase::Sample32>(
(presentation_time - event_times[0]).InMicroseconds())},
{"EventLatency.TotalLatency",
static_cast<base::HistogramBase::Sample32>(
(presentation_time - event_times[1]).InMicroseconds())},
{"EventLatency.TotalLatency",
static_cast<base::HistogramBase::Sample32>(
(presentation_time - event_times[2]).InMicroseconds())},
};
for (const auto& expected_latency : expected_latencies) {
histogram_tester.ExpectBucketCount(expected_latency.name,
expected_latency.latency_ms, 1);
}
}
TEST_F(CompositorFrameReportingControllerTest,
EventLatencyScrollTotalForPresentedFrameReported) {
base::HistogramTester histogram_tester;
const bool kScrollIsInertial = true;
const bool kScrollIsNotInertial = false;
std::unique_ptr<EventMetrics> event_metrics_ptrs[] = {
CreateScrollBeginEventMetrics(ui::ScrollInputType::kWheel),
CreateScrollUpdateEventMetrics(
ui::ScrollInputType::kWheel, kScrollIsNotInertial,
ScrollUpdateEventMetrics::ScrollUpdateType::kStarted, std::nullopt),
CreateScrollUpdateEventMetrics(
ui::ScrollInputType::kWheel, kScrollIsNotInertial,
ScrollUpdateEventMetrics::ScrollUpdateType::kContinued, std::nullopt),
CreateScrollUpdateEventMetrics(
ui::ScrollInputType::kWheel, kScrollIsInertial,
ScrollUpdateEventMetrics::ScrollUpdateType::kContinued, std::nullopt),
CreateScrollBeginEventMetrics(ui::ScrollInputType::kTouchscreen),
CreateScrollUpdateEventMetrics(
ui::ScrollInputType::kTouchscreen, kScrollIsNotInertial,
ScrollUpdateEventMetrics::ScrollUpdateType::kStarted, std::nullopt),
CreateScrollUpdateEventMetrics(
ui::ScrollInputType::kTouchscreen, kScrollIsNotInertial,
ScrollUpdateEventMetrics::ScrollUpdateType::kContinued, std::nullopt),
CreateScrollUpdateEventMetrics(
ui::ScrollInputType::kTouchscreen, kScrollIsInertial,
ScrollUpdateEventMetrics::ScrollUpdateType::kContinued, std::nullopt),
};
EXPECT_THAT(event_metrics_ptrs, Each(NotNull()));
EventMetrics::List events_metrics(
std::make_move_iterator(std::begin(event_metrics_ptrs)),
std::make_move_iterator(std::end(event_metrics_ptrs)));
std::vector<base::TimeTicks> event_times = GetEventTimestamps(events_metrics);
SimulateSubmitCompositorFrame({std::move(events_metrics), {}, {}});
viz::FrameTimingDetails details;
details.received_compositor_frame_timestamp = AdvanceNowByMs(10);
details.draw_start_timestamp = AdvanceNowByMs(10);
details.swap_timings.swap_start = AdvanceNowByMs(10);
details.swap_timings.swap_end = AdvanceNowByMs(10);
details.presentation_feedback.timestamp = AdvanceNowByMs(10);
reporting_controller_.DidPresentCompositorFrame(*current_token_, details);
struct {
const char* name;
const base::HistogramBase::Count32 count;
} expected_counts[] = {
{"EventLatency.GestureScrollBegin.Wheel.TotalLatency2", 1},
{"EventLatency.FirstGestureScrollUpdate.Wheel.TotalLatency2", 1},
{"EventLatency.GestureScrollUpdate.Wheel.TotalLatency2", 1},
{"EventLatency.InertialGestureScrollUpdate.Wheel.TotalLatency2", 1},
{"EventLatency.GestureScrollBegin.Touchscreen.TotalLatency2", 1},
{"EventLatency.FirstGestureScrollUpdate.Touchscreen.TotalLatency2", 1},
{"EventLatency.GestureScrollUpdate.Touchscreen.TotalLatency", 1},
{"EventLatency.GestureScrollUpdate.Touchscreen.TotalLatency2", 1},
{"EventLatency.InertialGestureScrollUpdate.Touchscreen.TotalLatency2", 1},
{"EventLatency.GestureScrollBegin.TotalLatency2", 2},
{"EventLatency.GestureScrollBegin.GenerationToBrowserMain", 2},
{"EventLatency.FirstGestureScrollUpdate.TotalLatency2", 2},
{"EventLatency.FirstGestureScrollUpdate.GenerationToBrowserMain", 2},
{"EventLatency.GestureScrollUpdate.TotalLatency2", 2},
{"EventLatency.GestureScrollUpdate.GenerationToBrowserMain", 2},
{"EventLatency.InertialGestureScrollUpdate.TotalLatency2", 2},
{"EventLatency.InertialGestureScrollUpdate.GenerationToBrowserMain", 2},
{"EventLatency.TotalLatency", 8},
};
for (const auto& expected_count : expected_counts) {
histogram_tester.ExpectTotalCount(expected_count.name,
expected_count.count);
}
const base::TimeTicks presentation_time =
details.presentation_feedback.timestamp;
struct {
const char* name;
const base::HistogramBase::Sample32 latency_ms;
} expected_latencies[] = {
{"EventLatency.GestureScrollBegin.Wheel.TotalLatency2",
static_cast<base::HistogramBase::Sample32>(
(presentation_time - event_times[0]).InMicroseconds())},
{"EventLatency.FirstGestureScrollUpdate.Wheel.TotalLatency2",
static_cast<base::HistogramBase::Sample32>(
(presentation_time - event_times[1]).InMicroseconds())},
{"EventLatency.GestureScrollUpdate.Wheel.TotalLatency2",
static_cast<base::HistogramBase::Sample32>(
(presentation_time - event_times[2]).InMicroseconds())},
{"EventLatency.InertialGestureScrollUpdate.Wheel.TotalLatency2",
static_cast<base::HistogramBase::Sample32>(
(presentation_time - event_times[3]).InMicroseconds())},
{"EventLatency.GestureScrollBegin.Touchscreen.TotalLatency2",
static_cast<base::HistogramBase::Sample32>(
(presentation_time - event_times[4]).InMicroseconds())},
{"EventLatency.FirstGestureScrollUpdate.Touchscreen.TotalLatency2",
static_cast<base::HistogramBase::Sample32>(
(presentation_time - event_times[5]).InMicroseconds())},
{"EventLatency.GestureScrollUpdate.Touchscreen.TotalLatency",
static_cast<base::HistogramBase::Sample32>(
(presentation_time - event_times[6]).InMicroseconds())},
{"EventLatency.GestureScrollUpdate.Touchscreen.TotalLatency2",
static_cast<base::HistogramBase::Sample32>(
(presentation_time - event_times[6]).InMicroseconds())},
{"EventLatency.InertialGestureScrollUpdate.Touchscreen.TotalLatency2",
static_cast<base::HistogramBase::Sample32>(
(presentation_time - event_times[7]).InMicroseconds())},
};
for (const auto& expected_latency : expected_latencies) {
histogram_tester.ExpectBucketCount(expected_latency.name,
expected_latency.latency_ms, 1);
}
}
TEST_F(CompositorFrameReportingControllerTest,
EventLatencyMainRepaintedScroll) {
base::HistogramTester histogram_tester;
std::unique_ptr<EventMetrics> metrics_1 = CreateScrollUpdateEventMetrics(
ui::ScrollInputType::kWheel, false,
ScrollUpdateEventMetrics::ScrollUpdateType::kStarted, std::nullopt);
base::TimeTicks start_time_1 = metrics_1->GetDispatchStageTimestamp(
EventMetrics::DispatchStage::kGenerated);
std::unique_ptr<EventMetrics> metrics_2 = CreateScrollUpdateEventMetrics(
ui::ScrollInputType::kWheel, false,
ScrollUpdateEventMetrics::ScrollUpdateType::kContinued, std::nullopt);
metrics_2->set_requires_main_thread_update();
base::TimeTicks start_time_2 = metrics_2->GetDispatchStageTimestamp(
EventMetrics::DispatchStage::kGenerated);
SimulateBeginImplFrame();
SimulateBeginMainFrame();
reporting_controller_.OnFinishImplFrame(current_id_,
true);
EventMetrics::List metrics_list;
metrics_list.push_back(std::move(metrics_1));
metrics_list.push_back(std::move(metrics_2));
SubmitInfo submit_info = {*current_token_, AdvanceNowByMs(10)};
submit_info.events_metrics = {{}, std::move(metrics_list), {}};
reporting_controller_.DidSubmitCompositorFrame(submit_info, current_id_, {});
viz::FrameTimingDetails details_1 = {};
details_1.presentation_feedback.timestamp = AdvanceNowByMs(10);
reporting_controller_.DidPresentCompositorFrame(*current_token_, details_1);
SimulateCommit(nullptr);
SimulateActivate();
SimulateBeginImplFrame();
reporting_controller_.OnFinishImplFrame(current_id_,
true);
SimulateSubmitCompositorFrame({});
viz::FrameTimingDetails details_2 = {};
details_2.presentation_feedback.timestamp = AdvanceNowByMs(10);
reporting_controller_.DidPresentCompositorFrame(*current_token_, details_2);
base::TimeDelta expected_latency_1 =
details_1.presentation_feedback.timestamp - start_time_1;
histogram_tester.ExpectBucketCount(
"EventLatency.FirstGestureScrollUpdate.Wheel.TotalLatency2",
expected_latency_1.InMicroseconds(), 1);
base::TimeDelta expected_latency_2 =
details_2.presentation_feedback.timestamp - start_time_2;
histogram_tester.ExpectBucketCount(
"EventLatency.GestureScrollUpdate.Wheel.TotalLatency2",
expected_latency_2.InMicroseconds(), 1);
}
TEST_F(CompositorFrameReportingControllerTest,
EventLatencyPinchTotalForPresentedFrameReported) {
base::HistogramTester histogram_tester;
std::unique_ptr<EventMetrics> event_metrics_ptrs[] = {
CreatePinchEventMetrics(ui::EventType::kGesturePinchBegin,
ui::ScrollInputType::kWheel),
CreatePinchEventMetrics(ui::EventType::kGesturePinchUpdate,
ui::ScrollInputType::kWheel),
CreatePinchEventMetrics(ui::EventType::kGesturePinchBegin,
ui::ScrollInputType::kTouchscreen),
CreatePinchEventMetrics(ui::EventType::kGesturePinchUpdate,
ui::ScrollInputType::kTouchscreen),
};
EXPECT_THAT(event_metrics_ptrs, Each(NotNull()));
EventMetrics::List events_metrics(
std::make_move_iterator(std::begin(event_metrics_ptrs)),
std::make_move_iterator(std::end(event_metrics_ptrs)));
std::vector<base::TimeTicks> event_times = GetEventTimestamps(events_metrics);
SimulateSubmitCompositorFrame({std::move(events_metrics), {}, {}});
viz::FrameTimingDetails details;
details.received_compositor_frame_timestamp = AdvanceNowByMs(10);
details.draw_start_timestamp = AdvanceNowByMs(10);
details.swap_timings.swap_start = AdvanceNowByMs(10);
details.swap_timings.swap_end = AdvanceNowByMs(10);
details.presentation_feedback.timestamp = AdvanceNowByMs(10);
reporting_controller_.DidPresentCompositorFrame(*current_token_, details);
struct {
const char* name;
const base::HistogramBase::Count32 count;
} expected_counts[] = {
{"EventLatency.GesturePinchBegin.Touchpad.TotalLatency", 1},
{"EventLatency.GesturePinchUpdate.Touchpad.TotalLatency", 1},
{"EventLatency.GesturePinchBegin.Touchscreen.TotalLatency", 1},
{"EventLatency.GesturePinchUpdate.Touchscreen.TotalLatency", 1},
{"EventLatency.TotalLatency", 4},
};
for (const auto& expected_count : expected_counts) {
histogram_tester.ExpectTotalCount(expected_count.name,
expected_count.count);
}
const base::TimeTicks presentation_time =
details.presentation_feedback.timestamp;
struct {
const char* name;
const base::HistogramBase::Sample32 latency_ms;
} expected_latencies[] = {
{"EventLatency.GesturePinchBegin.Touchpad.TotalLatency",
static_cast<base::HistogramBase::Sample32>(
(presentation_time - event_times[0]).InMicroseconds())},
{"EventLatency.GesturePinchUpdate.Touchpad.TotalLatency",
static_cast<base::HistogramBase::Sample32>(
(presentation_time - event_times[1]).InMicroseconds())},
{"EventLatency.GesturePinchBegin.Touchscreen.TotalLatency",
static_cast<base::HistogramBase::Sample32>(
(presentation_time - event_times[2]).InMicroseconds())},
{"EventLatency.GesturePinchUpdate.Touchscreen.TotalLatency",
static_cast<base::HistogramBase::Sample32>(
(presentation_time - event_times[3]).InMicroseconds())},
};
for (const auto& expected_latency : expected_latencies) {
histogram_tester.ExpectBucketCount(expected_latency.name,
expected_latency.latency_ms, 1);
}
}
TEST_F(CompositorFrameReportingControllerTest,
EventLatencyForDidNotPresentFrameReportedOnNextPresent) {
base::HistogramTester histogram_tester;
std::unique_ptr<EventMetrics> event_metrics_ptrs[] = {
CreateEventMetrics(ui::EventType::kTouchPressed, std::nullopt),
CreateEventMetrics(ui::EventType::kTouchMoved, std::nullopt),
CreateEventMetrics(ui::EventType::kTouchMoved, std::nullopt),
};
EXPECT_THAT(event_metrics_ptrs, Each(NotNull()));
EventMetrics::List events_metrics(
std::make_move_iterator(std::begin(event_metrics_ptrs)),
std::make_move_iterator(std::end(event_metrics_ptrs)));
std::vector<base::TimeTicks> event_times = GetEventTimestamps(events_metrics);
SimulateSubmitCompositorFrame({std::move(events_metrics), {}, {}});
IncrementCurrentId();
SimulateSubmitCompositorFrame({});
const base::TimeTicks presentation_time = AdvanceNowByMs(10);
viz::FrameTimingDetails details;
details.presentation_feedback.timestamp = presentation_time;
reporting_controller_.DidPresentCompositorFrame(*current_token_, details);
struct {
const char* name;
const base::HistogramBase::Count32 count;
} expected_counts[] = {
{"EventLatency.TouchPressed.TotalLatency", 1},
{"EventLatency.TouchMoved.TotalLatency", 2},
{"EventLatency.TotalLatency", 3},
};
for (const auto& expected_count : expected_counts) {
histogram_tester.ExpectTotalCount(expected_count.name,
expected_count.count);
}
struct {
const char* name;
const base::HistogramBase::Sample32 latency_ms;
} expected_latencies[] = {
{"EventLatency.TouchPressed.TotalLatency",
static_cast<base::HistogramBase::Sample32>(
(presentation_time - event_times[0]).InMicroseconds())},
{"EventLatency.TouchMoved.TotalLatency",
static_cast<base::HistogramBase::Sample32>(
(presentation_time - event_times[1]).InMicroseconds())},
{"EventLatency.TouchMoved.TotalLatency",
static_cast<base::HistogramBase::Sample32>(
(presentation_time - event_times[2]).InMicroseconds())},
{"EventLatency.TotalLatency",
static_cast<base::HistogramBase::Sample32>(
(presentation_time - event_times[0]).InMicroseconds())},
{"EventLatency.TotalLatency",
static_cast<base::HistogramBase::Sample32>(
(presentation_time - event_times[1]).InMicroseconds())},
{"EventLatency.TotalLatency",
static_cast<base::HistogramBase::Sample32>(
(presentation_time - event_times[2]).InMicroseconds())},
};
for (const auto& expected_latency : expected_latencies) {
histogram_tester.ExpectBucketCount(expected_latency.name,
expected_latency.latency_ms, 1);
}
}
TEST_F(CompositorFrameReportingControllerTest,
NewMainUpdateIsNotPartialUpdate) {
SimulateBeginMainFrame();
reporting_controller_.OnFinishImplFrame(current_id_,
true);
SubmitInfo submit_info = {1u, AdvanceNowByMs(10)};
reporting_controller_.DidSubmitCompositorFrame(submit_info, current_id_, {});
viz::FrameTimingDetails details = {};
details.presentation_feedback.timestamp = AdvanceNowByMs(10);
reporting_controller_.DidPresentCompositorFrame(1u, details);
reporting_controller_.NotifyReadyToCommit(nullptr);
reporting_controller_.WillCommit();
reporting_controller_.DidCommit();
reporting_controller_.WillActivate();
reporting_controller_.DidActivate();
const auto previous_id = current_id_;
SimulateBeginMainFrame();
reporting_controller_.OnFinishImplFrame(current_id_,
true);
SubmitInfo submit_info_main = {1u, AdvanceNowByMs(10)};
reporting_controller_.DidSubmitCompositorFrame(submit_info_main, current_id_,
previous_id);
details.presentation_feedback.timestamp = AdvanceNowByMs(10);
reporting_controller_.DidPresentCompositorFrame(1u, details);
EXPECT_EQ(2u, frame_sorter_.total_frames());
EXPECT_EQ(1u, frame_sorter_.total_partial());
EXPECT_EQ(1u, reporting_controller_.GetBlockingReportersCount());
EXPECT_EQ(1u, reporting_controller_.GetBlockedReportersCount());
reporting_controller_.ResetReporters();
reporting_controller_.ClearFrameSequenceTrackerCollection();
reporting_controller_.SetFrameSorter(nullptr);
}
TEST_F(CompositorFrameReportingControllerTest,
DependentDroppedFrameTerminatesReporterImmediately) {
SimulateBeginMainFrame();
reporting_controller_.OnFinishImplFrame(current_id_,
true);
SimulateBeginImplFrame();
reporting_controller_.OnFinishImplFrame(current_id_,
true);
SubmitInfo submit_info = {1u, AdvanceNowByMs(10)};
reporting_controller_.DidSubmitCompositorFrame(submit_info, current_id_, {});
viz::FrameTimingDetails details_1 = {};
details_1.presentation_feedback.timestamp = AdvanceNowByMs(10);
reporting_controller_.DidPresentCompositorFrame(1u, details_1);
EXPECT_EQ(1u, reporting_controller_.GetBlockingReportersCount());
EXPECT_EQ(1u, reporting_controller_.GetBlockedReportersCount());
EXPECT_EQ(1u, reporting_controller_.GetAdoptedReportersCount());
EXPECT_EQ(0u, frame_sorter_.total_frames());
EXPECT_EQ(0u, frame_sorter_.total_dropped());
SimulateBeginImplFrame();
reporting_controller_.OnFinishImplFrame(current_id_,
true);
SubmitInfo submit_info2 = {2u, AdvanceNowByMs(10)};
reporting_controller_.DidSubmitCompositorFrame(submit_info2, current_id_, {});
viz::FrameTimingDetails details_2 = {};
details_2.presentation_feedback.timestamp = AdvanceNowByMs(10);
details_2.presentation_feedback.flags |= gfx::PresentationFeedback::kFailure;
reporting_controller_.DidPresentCompositorFrame(2u, details_2);
EXPECT_EQ(1u, reporting_controller_.GetBlockingReportersCount());
EXPECT_EQ(2u, reporting_controller_.GetBlockedReportersCount());
EXPECT_EQ(1u, reporting_controller_.GetAdoptedReportersCount());
EXPECT_EQ(1u, frame_sorter_.total_frames());
EXPECT_EQ(1u, frame_sorter_.total_dropped());
reporting_controller_.ResetReporters();
reporting_controller_.ClearFrameSequenceTrackerCollection();
reporting_controller_.SetFrameSorter(nullptr);
}
TEST_F(CompositorFrameReportingControllerTest,
SkippedFramesFromDisplayCompositorAreDropped) {
SimulatePresentCompositorFrame();
EXPECT_EQ(1u, frame_sorter_.total_frames());
EXPECT_EQ(0u, frame_sorter_.total_partial());
EXPECT_EQ(0u, frame_sorter_.total_dropped());
SimulatePresentCompositorFrame();
EXPECT_EQ(2u, frame_sorter_.total_frames());
EXPECT_EQ(0u, frame_sorter_.total_partial());
EXPECT_EQ(0u, frame_sorter_.total_dropped());
const uint32_t kSkipFrames = 5;
for (uint32_t i = 0; i < kSkipFrames; ++i)
IncrementCurrentId();
SimulatePresentCompositorFrame();
EXPECT_EQ(3u + kSkipFrames, frame_sorter_.total_frames());
EXPECT_EQ(0u, frame_sorter_.total_partial());
EXPECT_EQ(kSkipFrames, frame_sorter_.total_dropped());
frame_sorter_.Reset(true);
reporting_controller_.OnStoppedRequestingBeginFrames();
for (uint32_t i = 0; i < kSkipFrames; ++i)
IncrementCurrentId();
SimulatePresentCompositorFrame();
EXPECT_EQ(1u, frame_sorter_.total_frames());
EXPECT_EQ(0u, frame_sorter_.total_partial());
EXPECT_EQ(0u, frame_sorter_.total_dropped());
reporting_controller_.ResetReporters();
reporting_controller_.ClearFrameSequenceTrackerCollection();
reporting_controller_.SetFrameSorter(nullptr);
}
TEST_F(CompositorFrameReportingControllerTest,
SkippedFramesFromDisplayCompositorAreDroppedUpToLimit) {
SimulatePresentCompositorFrame();
EXPECT_EQ(1u, frame_sorter_.total_frames());
EXPECT_EQ(0u, frame_sorter_.total_partial());
EXPECT_EQ(0u, frame_sorter_.total_dropped());
SimulatePresentCompositorFrame();
EXPECT_EQ(2u, frame_sorter_.total_frames());
EXPECT_EQ(0u, frame_sorter_.total_partial());
EXPECT_EQ(0u, frame_sorter_.total_dropped());
const uint32_t kSkipFrames = 101;
const uint32_t kSkipFramesActual = 0;
for (uint32_t i = 0; i < kSkipFrames; ++i)
IncrementCurrentId();
SimulatePresentCompositorFrame();
EXPECT_EQ(3u + kSkipFramesActual, frame_sorter_.total_frames());
EXPECT_EQ(0u, frame_sorter_.total_partial());
EXPECT_EQ(kSkipFramesActual, frame_sorter_.total_dropped());
}
TEST_F(CompositorFrameReportingControllerTest,
CompositorFrameBlockedOnMainFrameWithNoDamage) {
viz::BeginFrameId current_id_1(1, 1);
viz::BeginFrameArgs args_1 = SimulateBeginFrameArgs(current_id_1);
viz::BeginFrameId current_id_2(1, 2);
viz::BeginFrameArgs args_2 = SimulateBeginFrameArgs(current_id_2);
viz::BeginFrameId current_id_3(1, 3);
viz::BeginFrameArgs args_3 = SimulateBeginFrameArgs(current_id_3);
viz::BeginFrameId current_id_4(1, 4);
viz::BeginFrameArgs args_4 = SimulateBeginFrameArgs(current_id_4);
reporting_controller_.WillBeginImplFrame(args_1,
false);
reporting_controller_.WillBeginMainFrame(args_1);
reporting_controller_.OnFinishImplFrame(current_id_1,
true);
EXPECT_EQ(0u, frame_sorter_.total_dropped());
reporting_controller_.DidNotProduceFrame(args_1.frame_id,
FrameSkippedReason::kWaitingOnMain);
reporting_controller_.WillBeginImplFrame(args_2,
false);
reporting_controller_.OnFinishImplFrame(args_2.frame_id,
true);
reporting_controller_.DidNotProduceFrame(args_2.frame_id,
FrameSkippedReason::kWaitingOnMain);
reporting_controller_.WillBeginImplFrame(args_3,
false);
reporting_controller_.OnFinishImplFrame(args_3.frame_id,
true);
reporting_controller_.DidNotProduceFrame(args_3.frame_id,
FrameSkippedReason::kWaitingOnMain);
EXPECT_EQ(1u, reporting_controller_.GetBlockingReportersCount());
EXPECT_EQ(3u, reporting_controller_.GetBlockedReportersCount());
EXPECT_EQ(0u, frame_sorter_.total_partial());
EXPECT_EQ(0u, frame_sorter_.total_dropped());
EXPECT_EQ(0u, frame_sorter_.total_frames());
reporting_controller_.BeginMainFrameAborted(
args_1.frame_id, CommitEarlyOutReason::kFinishedNoUpdates);
reporting_controller_.DidNotProduceFrame(args_1.frame_id,
FrameSkippedReason::kNoDamage);
EXPECT_EQ(0u, frame_sorter_.total_dropped());
reporting_controller_.WillBeginImplFrame(args_4,
false);
reporting_controller_.WillBeginMainFrame(args_4);
EXPECT_EQ(4u, frame_sorter_.total_frames());
EXPECT_EQ(0u, frame_sorter_.total_partial());
EXPECT_EQ(0u, frame_sorter_.total_dropped());
}
TEST_F(CompositorFrameReportingControllerTest,
SkippedFramesFromDisplayCompositorHaveSmoothThread) {
auto thread_type_compositor = FrameInfo::SmoothThread::kSmoothCompositor;
tracker_collection_.StartSequence(
FrameSequenceTrackerType::kCompositorAnimation);
EXPECT_EQ(tracker_collection_.GetSmoothThread(), thread_type_compositor);
frame_sorter_.OnFirstContentfulPaintReceived();
SimulatePresentCompositorFrame();
EXPECT_EQ(1u, frame_sorter_.total_frames());
EXPECT_EQ(0u, frame_sorter_.total_partial());
EXPECT_EQ(0u, frame_sorter_.total_dropped());
SimulatePresentCompositorFrame();
EXPECT_EQ(2u, frame_sorter_.total_frames());
EXPECT_EQ(0u, frame_sorter_.total_partial());
EXPECT_EQ(0u, frame_sorter_.total_dropped());
const uint32_t kSkipFrames_1 = 5;
for (uint32_t i = 0; i < kSkipFrames_1; ++i)
IncrementCurrentId();
SimulatePresentCompositorFrame();
EXPECT_EQ(3u + kSkipFrames_1, frame_sorter_.total_frames());
EXPECT_EQ(0u, frame_sorter_.total_partial());
EXPECT_EQ(kSkipFrames_1, frame_sorter_.total_dropped());
tracker_collection_.StopSequence(
FrameSequenceTrackerType::kCompositorAnimation);
EXPECT_EQ(tracker_collection_.GetSmoothThread(),
FrameInfo::SmoothThread::kSmoothNone);
const uint32_t kSkipFrames_2 = 7;
for (uint32_t i = 0; i < kSkipFrames_2; ++i)
IncrementCurrentId();
SimulatePresentCompositorFrame();
EXPECT_EQ(4u + kSkipFrames_1 + kSkipFrames_2, frame_sorter_.total_frames());
EXPECT_EQ(0u, frame_sorter_.total_partial());
EXPECT_EQ(kSkipFrames_1 + kSkipFrames_2, frame_sorter_.total_dropped());
tracker_collection_.StartSequence(
FrameSequenceTrackerType::kCompositorAnimation);
EXPECT_EQ(tracker_collection_.GetSmoothThread(), thread_type_compositor);
const uint32_t kSkipFrames_3 = 10;
for (uint32_t i = 0; i < kSkipFrames_3; ++i)
IncrementCurrentId();
SimulatePresentCompositorFrame();
EXPECT_EQ(5u + kSkipFrames_1 + kSkipFrames_2 + kSkipFrames_3,
frame_sorter_.total_frames());
EXPECT_EQ(0u, frame_sorter_.total_partial());
EXPECT_EQ(kSkipFrames_1 + kSkipFrames_2 + kSkipFrames_3,
frame_sorter_.total_dropped());
}
TEST_F(CompositorFrameReportingControllerTest,
SkippedFramesFromClientRequestedThrottlingAreDropped) {
SimulatePresentCompositorFrame();
EXPECT_EQ(1u, frame_sorter_.total_frames());
EXPECT_EQ(0u, frame_sorter_.total_partial());
EXPECT_EQ(0u, frame_sorter_.total_dropped());
SimulatePresentCompositorFrame();
EXPECT_EQ(2u, frame_sorter_.total_frames());
EXPECT_EQ(0u, frame_sorter_.total_partial());
EXPECT_EQ(0u, frame_sorter_.total_dropped());
const uint32_t kTotalFrames = 5;
const uint64_t kThrottledFrames = 4;
for (uint32_t i = 0; i < kTotalFrames; ++i)
IncrementCurrentId();
args_.frames_throttled_since_last = kThrottledFrames;
SimulatePresentCompositorFrame();
EXPECT_EQ(3u + kTotalFrames - kThrottledFrames, frame_sorter_.total_frames());
EXPECT_EQ(0u, frame_sorter_.total_partial());
EXPECT_EQ(kTotalFrames - kThrottledFrames, frame_sorter_.total_dropped());
}
TEST_F(CompositorFrameReportingControllerTest,
DroppedFrameCountOnMainFrameAbort) {
for (int i = 0; i < 5; ++i) {
SimulateBeginImplFrame();
SimulateBeginMainFrame();
reporting_controller_.OnFinishImplFrame(current_id_,
true);
reporting_controller_.BeginMainFrameAborted(
current_id_, CommitEarlyOutReason::kFinishedNoUpdates);
}
EXPECT_EQ(0u, frame_sorter_.total_dropped());
for (int i = 0; i < 5; ++i) {
SimulateBeginImplFrame();
SimulateBeginMainFrame();
reporting_controller_.OnFinishImplFrame(current_id_,
true);
reporting_controller_.BeginMainFrameAborted(
current_id_, CommitEarlyOutReason::kAbortedDeferredCommit);
SimulateSubmitCompositorFrame({});
}
SimulatePresentCompositorFrame();
EXPECT_EQ(5u, frame_sorter_.total_dropped());
}
TEST_F(CompositorFrameReportingControllerTest,
HandleOutOfOrderPresentationFeedback) {
SimulateSubmitCompositorFrame({});
SimulateSubmitCompositorFrame({});
const uint32_t frame_token_2 = *current_token_;
SimulateSubmitCompositorFrame({});
const uint32_t frame_token_3 = *current_token_;
viz::FrameTimingDetails details_2;
details_2.presentation_feedback = {AdvanceNowByMs(10), base::TimeDelta(),
gfx::PresentationFeedback::kFailure};
reporting_controller_.DidPresentCompositorFrame(frame_token_2, details_2);
DCHECK_EQ(1u, frame_sorter_.total_frames());
DCHECK_EQ(1u, frame_sorter_.total_dropped());
viz::FrameTimingDetails details_3;
details_3.presentation_feedback.timestamp = AdvanceNowByMs(10);
reporting_controller_.DidPresentCompositorFrame(frame_token_3, details_3);
DCHECK_EQ(3u, frame_sorter_.total_frames());
DCHECK_EQ(2u, frame_sorter_.total_dropped());
}
TEST_F(CompositorFrameReportingControllerTest,
NewMainThreadUpdateNotReportedAsDropped) {
auto thread_type_main = FrameInfo::SmoothThread::kSmoothMain;
tracker_collection_.StartSequence(
FrameSequenceTrackerType::kMainThreadAnimation);
EXPECT_EQ(tracker_collection_.GetSmoothThread(), thread_type_main);
frame_sorter_.OnFirstContentfulPaintReceived();
SimulateBeginMainFrame();
reporting_controller_.OnFinishImplFrame(current_id_,
true);
SubmitInfo submit_info = {1u, AdvanceNowByMs(10)};
reporting_controller_.DidSubmitCompositorFrame(submit_info, current_id_, {});
viz::FrameTimingDetails details = {};
details.presentation_feedback.timestamp = AdvanceNowByMs(10);
reporting_controller_.DidPresentCompositorFrame(1u, details);
SimulateCommit(nullptr);
const auto previous_id = current_id_;
SimulateBeginMainFrame();
DCHECK_NE(previous_id, current_id_);
reporting_controller_.OnFinishImplFrame(current_id_,
true);
reporting_controller_.WillActivate();
reporting_controller_.DidActivate();
SubmitInfo submit_info2 = {2u, AdvanceNowByMs(10)};
reporting_controller_.DidSubmitCompositorFrame(submit_info2, current_id_,
previous_id);
details.presentation_feedback.timestamp = AdvanceNowByMs(10);
reporting_controller_.DidPresentCompositorFrame(2u, details);
SimulateCommit(nullptr);
SimulatePresentCompositorFrame();
EXPECT_EQ(2u, frame_sorter_.total_partial());
}
TEST_F(CompositorFrameReportingControllerTest,
NoUpdateCompositorWithJankyMain) {
frame_sorter_.OnFirstContentfulPaintReceived();
SimulateBeginMainFrame();
EXPECT_EQ(1, reporting_controller_.ActiveReporters());
EXPECT_EQ(0u, frame_sorter_.total_frames());
reporting_controller_.OnFinishImplFrame(current_id_,
true);
reporting_controller_.DidNotProduceFrame(current_id_,
FrameSkippedReason::kWaitingOnMain);
EXPECT_EQ(0u, frame_sorter_.total_frames());
SimulateActivate();
EXPECT_EQ(1, reporting_controller_.ActiveReporters());
EXPECT_EQ(0u, frame_sorter_.total_frames());
SimulateBeginImplFrame();
EXPECT_EQ(2, reporting_controller_.ActiveReporters());
EXPECT_EQ(0u, frame_sorter_.total_frames());
reporting_controller_.OnFinishImplFrame(current_id_,
true);
SimulatePresentCompositorFrame();
EXPECT_EQ(3u, frame_sorter_.total_frames());
}
TEST_F(CompositorFrameReportingControllerTest, MainFrameBeforeCommit) {
viz::BeginFrameArgs args1 = SimulateBeginFrameArgs({1, 1});
viz::BeginFrameArgs args2 = SimulateBeginFrameArgs({1, 2});
viz::BeginFrameArgs args3 = SimulateBeginFrameArgs({1, 3});
viz::BeginFrameArgs args4 = SimulateBeginFrameArgs({1, 4});
reporting_controller_.WillBeginImplFrame(args1, false);
reporting_controller_.WillBeginMainFrame(args1);
reporting_controller_.NotifyReadyToCommit(nullptr);
reporting_controller_.WillBeginImplFrame(args2, false);
reporting_controller_.WillBeginMainFrame(args2);
EXPECT_EQ(2, reporting_controller_.ActiveReporters());
EXPECT_TRUE(reporting_controller_.HasReporterAt(
CompositorFrameReportingController::PipelineStage::kBeginMainFrame));
EXPECT_TRUE(reporting_controller_.HasReporterAt(
CompositorFrameReportingController::PipelineStage::kReadyToCommit));
reporting_controller_.WillCommit();
reporting_controller_.DidCommit();
reporting_controller_.NotifyReadyToCommit(nullptr);
reporting_controller_.WillBeginImplFrame(args3, false);
EXPECT_EQ(3, reporting_controller_.ActiveReporters());
reporting_controller_.WillBeginMainFrame(args3);
EXPECT_EQ(3, reporting_controller_.ActiveReporters());
EXPECT_TRUE(reporting_controller_.HasReporterAt(
CompositorFrameReportingController::PipelineStage::kBeginMainFrame));
EXPECT_TRUE(reporting_controller_.HasReporterAt(
CompositorFrameReportingController::PipelineStage::kReadyToCommit));
EXPECT_TRUE(reporting_controller_.HasReporterAt(
CompositorFrameReportingController::PipelineStage::kCommit));
reporting_controller_.WillActivate();
reporting_controller_.DidActivate();
reporting_controller_.WillCommit();
reporting_controller_.DidCommit();
reporting_controller_.NotifyReadyToCommit(nullptr);
reporting_controller_.WillBeginImplFrame(args4, false);
EXPECT_EQ(4, reporting_controller_.ActiveReporters());
reporting_controller_.WillBeginMainFrame(args4);
EXPECT_EQ(4, reporting_controller_.ActiveReporters());
EXPECT_TRUE(reporting_controller_.HasReporterAt(
CompositorFrameReportingController::PipelineStage::kBeginMainFrame));
EXPECT_TRUE(reporting_controller_.HasReporterAt(
CompositorFrameReportingController::PipelineStage::kReadyToCommit));
EXPECT_TRUE(reporting_controller_.HasReporterAt(
CompositorFrameReportingController::PipelineStage::kCommit));
EXPECT_TRUE(reporting_controller_.HasReporterAt(
CompositorFrameReportingController::PipelineStage::kActivate));
}
TEST_F(CompositorFrameReportingControllerTest,
ScrollJankMetricsPresentationOrderAbortedMain) {
base::test::TestTraceProcessor ttp;
ttp.StartTrace("input");
std::unique_ptr<EventMetrics> metrics_1 = CreateScrollUpdateEventMetrics(
ui::ScrollInputType::kWheel, false,
ScrollUpdateEventMetrics::ScrollUpdateType::kStarted, std::nullopt);
std::unique_ptr<EventMetrics> metrics_2 = CreateScrollUpdateEventMetrics(
ui::ScrollInputType::kWheel, false,
ScrollUpdateEventMetrics::ScrollUpdateType::kContinued, std::nullopt);
std::unique_ptr<EventMetrics> metrics_3 = CreateScrollUpdateEventMetrics(
ui::ScrollInputType::kWheel, false,
ScrollUpdateEventMetrics::ScrollUpdateType::kContinued, std::nullopt);
SimulateBeginImplFrame();
viz::BeginFrameId bf1_id = current_id_;
SimulateBeginMainFrame();
reporting_controller_.OnFinishImplFrame(current_id_,
true);
EventMetrics::List metrics_list_1;
metrics_list_1.push_back(std::move(metrics_1));
++current_token_;
SubmitInfo submit_info = {*current_token_, AdvanceNowByMs(10)};
submit_info.events_metrics = {{}, std::move(metrics_list_1), {}};
reporting_controller_.DidSubmitCompositorFrame(submit_info, current_id_,
{});
viz::FrameTimingDetails details_1 = {};
details_1.presentation_feedback.timestamp = AdvanceNowByMs(10);
reporting_controller_.DidPresentCompositorFrame(*current_token_,
details_1);
SimulateBeginImplFrame();
viz::BeginFrameId bf2_id = current_id_;
reporting_controller_.OnFinishImplFrame(current_id_,
true);
SimulateCommit(nullptr);
SimulateBeginMainFrame();
EventMetrics::List metrics_list_2;
metrics_list_2.push_back(std::move(metrics_2));
++current_token_;
SubmitInfo submit_info2 = {*current_token_, AdvanceNowByMs(10)};
submit_info.events_metrics = {{}, std::move(metrics_list_2), {}};
reporting_controller_.DidSubmitCompositorFrame(submit_info2, current_id_,
{});
SimulateActivate();
reporting_controller_.BeginMainFrameAborted(
bf2_id, CommitEarlyOutReason::kFinishedNoUpdates);
SimulateBeginImplFrame();
reporting_controller_.OnFinishImplFrame(current_id_,
true);
SimulateBeginMainFrame();
viz::FrameTimingDetails details_2 = {};
details_2.presentation_feedback.timestamp = AdvanceNowByMs(10);
reporting_controller_.DidPresentCompositorFrame(*current_token_,
details_2);
++current_token_;
SubmitInfo submit_info3 = {*current_token_, AdvanceNowByMs(10)};
reporting_controller_.DidSubmitCompositorFrame(submit_info3, current_id_,
bf1_id);
viz::FrameTimingDetails details_3 = {};
details_3.presentation_feedback.timestamp = AdvanceNowByMs(10);
reporting_controller_.DidPresentCompositorFrame(*current_token_,
details_3);
absl::Status status = ttp.StopAndParseTrace();
ASSERT_TRUE(status.ok()) << status.message();
std::string query =
R"(
SELECT count(*) as cnt from slice
where name = 'OutOfOrderTerminatedFrame'
)";
auto result = ttp.RunQuery(query);
ASSERT_TRUE(result.has_value()) << result.error();
EXPECT_THAT(result.value(),
::testing::ElementsAre(std::vector<std::string>{"cnt"},
std::vector<std::string>{"0"}));
}
TEST_F(CompositorFrameReportingControllerTest,
ScrollJankMetricsPresentationOrderDroppedPartialOnMainScroll) {
base::HistogramTester histogram_tester;
base::test::TestTraceProcessor ttp;
ttp.StartTrace("input");
std::unique_ptr<EventMetrics> metrics_1 = CreateScrollUpdateEventMetrics(
ui::ScrollInputType::kWheel, false,
ScrollUpdateEventMetrics::ScrollUpdateType::kStarted, std::nullopt);
metrics_1->set_requires_main_thread_update();
std::unique_ptr<EventMetrics> metrics_2 = CreateScrollUpdateEventMetrics(
ui::ScrollInputType::kWheel, false,
ScrollUpdateEventMetrics::ScrollUpdateType::kContinued, std::nullopt);
metrics_2->set_requires_main_thread_update();
SimulateBeginImplFrame();
viz::BeginFrameId bf1_id = current_id_;
SimulateBeginMainFrame();
reporting_controller_.OnFinishImplFrame(current_id_,
true);
EventMetrics::List metrics_list_1;
metrics_list_1.push_back(std::move(metrics_1));
++current_token_;
SubmitInfo submit_info = {*current_token_, AdvanceNowByMs(10)};
submit_info.events_metrics = {{}, std::move(metrics_list_1), {}};
reporting_controller_.DidSubmitCompositorFrame(submit_info, current_id_,
{});
viz::FrameTimingDetails details_1 = {};
details_1.presentation_feedback.timestamp = AdvanceNowByMs(10);
reporting_controller_.DidPresentCompositorFrame(*current_token_,
details_1);
SimulateBeginImplFrame();
reporting_controller_.OnFinishImplFrame(current_id_,
true);
EventMetrics::List metrics_list_2;
metrics_list_2.push_back(std::move(metrics_2));
++current_token_;
SubmitInfo submit_info2 = {*current_token_, AdvanceNowByMs(10)};
submit_info.events_metrics = {{}, std::move(metrics_list_2), {}};
reporting_controller_.DidSubmitCompositorFrame(submit_info2, current_id_,
{});
viz::FrameTimingDetails details_2 = {};
details_2.presentation_feedback.timestamp = AdvanceNowByMs(10);
details_2.presentation_feedback.flags |= gfx::PresentationFeedback::kFailure;
reporting_controller_.DidPresentCompositorFrame(*current_token_,
details_2);
SimulateCommit(nullptr);
SimulateActivate();
SimulateBeginImplFrame();
reporting_controller_.OnFinishImplFrame(current_id_,
true);
++current_token_;
SubmitInfo submit_info3 = {*current_token_, AdvanceNowByMs(10)};
reporting_controller_.DidSubmitCompositorFrame(submit_info3, current_id_,
bf1_id);
viz::FrameTimingDetails details_3 = {};
details_3.presentation_feedback.timestamp = AdvanceNowByMs(10);
reporting_controller_.DidPresentCompositorFrame(*current_token_,
details_3);
absl::Status status = ttp.StopAndParseTrace();
ASSERT_TRUE(status.ok()) << status.message();
std::string query =
R"(
SELECT count(*) as cnt from slice
where name = 'OutOfOrderTerminatedFrame'
)";
auto result = ttp.RunQuery(query);
ASSERT_TRUE(result.has_value()) << result.error();
EXPECT_THAT(result.value(),
::testing::ElementsAre(std::vector<std::string>{"cnt"},
std::vector<std::string>{"0"}));
histogram_tester.ExpectTotalCount("Event.ScrollJank.MissedVsyncs.PerFrame",
1);
}
TEST_F(CompositorFrameReportingControllerTest,
ScrollJankMetricsPresentationOrderDroppedPartialOnImplScroll) {
base::HistogramTester histogram_tester;
base::test::TestTraceProcessor ttp;
ttp.StartTrace("input");
std::unique_ptr<EventMetrics> metrics_1 = CreateScrollUpdateEventMetrics(
ui::ScrollInputType::kWheel, false,
ScrollUpdateEventMetrics::ScrollUpdateType::kStarted, std::nullopt);
std::unique_ptr<EventMetrics> metrics_2 = CreateScrollUpdateEventMetrics(
ui::ScrollInputType::kWheel, false,
ScrollUpdateEventMetrics::ScrollUpdateType::kContinued, std::nullopt);
SimulateBeginImplFrame();
viz::BeginFrameId bf1_id = current_id_;
SimulateBeginMainFrame();
reporting_controller_.OnFinishImplFrame(current_id_,
true);
EventMetrics::List metrics_list_1;
metrics_list_1.push_back(std::move(metrics_1));
++current_token_;
SubmitInfo submit_info = {*current_token_, AdvanceNowByMs(10)};
submit_info.events_metrics = {{}, std::move(metrics_list_1), {}};
reporting_controller_.DidSubmitCompositorFrame(submit_info, current_id_,
{});
viz::FrameTimingDetails details_1 = {};
details_1.presentation_feedback.timestamp = AdvanceNowByMs(10);
details_1.presentation_feedback.flags |= gfx::PresentationFeedback::kFailure;
reporting_controller_.DidPresentCompositorFrame(*current_token_,
details_1);
SimulateBeginImplFrame();
reporting_controller_.OnFinishImplFrame(current_id_,
true);
SimulateCommit(nullptr);
SimulateActivate();
EventMetrics::List metrics_list_2;
metrics_list_2.push_back(std::move(metrics_2));
++current_token_;
SubmitInfo submit_info2 = {*current_token_, AdvanceNowByMs(10)};
submit_info2.events_metrics = {{}, std::move(metrics_list_2), {}};
reporting_controller_.DidSubmitCompositorFrame(submit_info2, current_id_,
bf1_id);
viz::FrameTimingDetails details_2 = {};
details_2.presentation_feedback.timestamp = AdvanceNowByMs(10);
reporting_controller_.DidPresentCompositorFrame(*current_token_,
details_2);
absl::Status status = ttp.StopAndParseTrace();
ASSERT_TRUE(status.ok()) << status.message();
std::string query =
R"(
SELECT count(*) as cnt from slice
where name = 'OutOfOrderTerminatedFrame'
)";
auto result = ttp.RunQuery(query);
ASSERT_TRUE(result.has_value()) << result.error();
EXPECT_THAT(result.value(),
::testing::ElementsAre(std::vector<std::string>{"cnt"},
std::vector<std::string>{"0"}));
histogram_tester.ExpectTotalCount("Event.ScrollJank.MissedVsyncs.PerFrame",
1);
}
TEST_F(CompositorFrameReportingControllerTest,
ScrollJankMetricsPresentationOrderReceivedDroppedEventsAreNotPassed) {
base::HistogramTester histogram_tester;
base::test::TestTraceProcessor ttp;
ttp.StartTrace("input");
std::unique_ptr<EventMetrics> metrics_1 = CreateScrollUpdateEventMetrics(
ui::ScrollInputType::kWheel, false,
ScrollUpdateEventMetrics::ScrollUpdateType::kStarted, std::nullopt);
metrics_1->set_requires_main_thread_update();
std::unique_ptr<EventMetrics> metrics_2 = CreateScrollUpdateEventMetrics(
ui::ScrollInputType::kWheel, false,
ScrollUpdateEventMetrics::ScrollUpdateType::kContinued, std::nullopt);
metrics_2->set_requires_main_thread_update();
std::unique_ptr<EventMetrics> metrics_3 = CreateScrollUpdateEventMetrics(
ui::ScrollInputType::kWheel, false,
ScrollUpdateEventMetrics::ScrollUpdateType::kContinued, std::nullopt);
metrics_3->set_requires_main_thread_update();
SimulateBeginImplFrame();
viz::BeginFrameId bf1_id = current_id_;
SimulateBeginMainFrame();
reporting_controller_.OnFinishImplFrame(current_id_,
true);
EventMetrics::List metrics_list_1;
metrics_list_1.push_back(std::move(metrics_1));
++current_token_;
SubmitInfo submit_info = {*current_token_, AdvanceNowByMs(10)};
submit_info.events_metrics = {{}, std::move(metrics_list_1), {}};
reporting_controller_.DidSubmitCompositorFrame(submit_info, current_id_,
{});
viz::FrameTimingDetails details_1 = {};
details_1.presentation_feedback.timestamp = AdvanceNowByMs(10);
reporting_controller_.DidPresentCompositorFrame(*current_token_,
details_1);
SimulateCommit(nullptr);
SimulateActivate();
SimulateBeginImplFrame();
viz::BeginFrameId bf2_id = current_id_;
reporting_controller_.OnFinishImplFrame(current_id_,
true);
SimulateBeginMainFrame();
EventMetrics::List metrics_list_2;
metrics_list_2.push_back(std::move(metrics_2));
++current_token_;
SubmitInfo submit_info2 = {*current_token_, AdvanceNowByMs(10)};
submit_info2.events_metrics = {{}, std::move(metrics_list_2), {}};
reporting_controller_.DidSubmitCompositorFrame(submit_info2, current_id_,
bf1_id);
viz::FrameTimingDetails details_2 = {};
details_2.presentation_feedback.timestamp = AdvanceNowByMs(10);
details_2.presentation_feedback.flags |= gfx::PresentationFeedback::kFailure;
reporting_controller_.DidPresentCompositorFrame(*current_token_,
details_2);
SimulateBeginImplFrame();
reporting_controller_.OnFinishImplFrame(current_id_,
true);
EventMetrics::List metrics_list_3;
metrics_list_3.push_back(std::move(metrics_3));
++current_token_;
SubmitInfo submit_info3 = {*current_token_, AdvanceNowByMs(10)};
submit_info3.events_metrics = {{}, std::move(metrics_list_3), {}};
reporting_controller_.DidSubmitCompositorFrame(submit_info3, current_id_,
bf1_id);
viz::FrameTimingDetails details_3 = {};
details_3.presentation_feedback.timestamp = AdvanceNowByMs(10);
reporting_controller_.DidPresentCompositorFrame(*current_token_,
details_3);
SimulateCommit(nullptr);
SimulateActivate();
SimulateBeginImplFrame();
reporting_controller_.OnFinishImplFrame(current_id_,
true);
++current_token_;
SubmitInfo submit_info4 = {*current_token_, AdvanceNowByMs(10)};
reporting_controller_.DidSubmitCompositorFrame(submit_info4, current_id_,
bf2_id);
viz::FrameTimingDetails details_4 = {};
details_4.presentation_feedback.timestamp = AdvanceNowByMs(10);
reporting_controller_.DidPresentCompositorFrame(*current_token_,
details_4);
absl::Status status = ttp.StopAndParseTrace();
ASSERT_TRUE(status.ok()) << status.message();
std::string query =
R"(
SELECT count(*) as cnt from slice
where name = 'OutOfOrderTerminatedFrame'
)";
auto result = ttp.RunQuery(query);
ASSERT_TRUE(result.has_value()) << result.error();
EXPECT_THAT(result.value(),
::testing::ElementsAre(std::vector<std::string>{"cnt"},
std::vector<std::string>{"0"}));
histogram_tester.ExpectTotalCount("Event.ScrollJank.MissedVsyncs.PerFrame",
2);
}
TEST_F(CompositorFrameReportingControllerTest, EmitsEventLatencyId) {
base::test::TestTraceProcessor ttp;
ttp.StartTrace("input");
std::unique_ptr<EventMetrics> metrics_1 = CreateScrollUpdateEventMetrics(
ui::ScrollInputType::kWheel, false,
ScrollUpdateEventMetrics::ScrollUpdateType::kStarted,
base::IdType64<class ui::LatencyInfo>(14));
std::unique_ptr<EventMetrics> metrics_2 = CreateEventMetrics(
ui::EventType::kTouchPressed, base::IdType64<class ui::LatencyInfo>(15));
EventMetrics::List metrics_list_1;
metrics_list_1.push_back(std::move(metrics_1));
metrics_list_1.push_back(std::move(metrics_2));
SimulateSubmitCompositorFrame({{}, std::move(metrics_list_1), {}});
SimulatePresentCompositorFrame();
absl::Status status = ttp.StopAndParseTrace();
ASSERT_TRUE(status.ok()) << status.message();
std::string query =
R"(
SELECT count(*) AS cnt
FROM slice
WHERE name = 'EventLatency'
AND (EXTRACT_ARG(arg_set_id, 'event_latency.event_latency_id') = 14
OR EXTRACT_ARG(arg_set_id, 'event_latency.event_latency_id') = 15)
)";
auto result = ttp.RunQuery(query);
ASSERT_TRUE(result.has_value()) << result.error();
EXPECT_THAT(result.value(),
::testing::ElementsAre(std::vector<std::string>{"cnt"},
std::vector<std::string>{"2"}));
}
constexpr const char kScrollJankMetricArgsQuery[] =
R"(
WITH event_latencies AS (
SELECT
ts,
EXTRACT_ARG(arg_set_id, 'event_latency.event_latency_id')
AS event_latency_id,
EXTRACT_ARG(arg_set_id, 'event_latency.is_janky_scrolled_frame')
AS is_janky
FROM slice
WHERE name = 'EventLatency'
), scroll_jank_v4_results AS (
SELECT
EXTRACT_ARG(
arg_set_id,
'scroll_jank_v4.updates.real.first_event_latency_id'
) AS event_latency_id,
EXTRACT_ARG(arg_set_id, 'scroll_jank_v4.is_janky') AS is_janky_v4
FROM slice
WHERE name = 'ScrollJankV4'
)
SELECT is_janky, is_janky_v4
FROM event_latencies
FULL OUTER JOIN scroll_jank_v4_results USING(event_latency_id)
ORDER BY ts ASC
)";
Test if we emit scroll-jank-metric-related arguments.
vsync | | | | | | | | |
input GSU1 GSU2 GSU3 non-GSU
| | | |
F1: |-----------------------|
F2: |-----------------------------|
F3: |-----------------------------|
F4: |-----------------------------|
F1 and F3 should have is_janky_scrolled_frame set to false while F2 should have
it set to true and F4 should not have a value for the argument.
*/
TEST_F(CompositorFrameReportingControllerTest, ScrollJankMetricArgs) {
base::test::TestTraceProcessor ttp;
ttp.StartTrace("input");
std::unique_ptr<EventMetrics> metrics_1 = CreateScrollUpdateEventMetrics(
ui::ScrollInputType::kWheel, false,
ScrollUpdateEventMetrics::ScrollUpdateType::kStarted,
EventMetrics::TraceId(123));
base::TimeTicks event1_generation_ts = metrics_1->GetDispatchStageTimestamp(
EventMetrics::DispatchStage::kGenerated);
std::unique_ptr<EventMetrics> metrics_2 = CreateScrollUpdateEventMetrics(
ui::ScrollInputType::kWheel, false,
ScrollUpdateEventMetrics::ScrollUpdateType::kContinued,
EventMetrics::TraceId(456));
base::TimeTicks event2_generation_ts = metrics_2->GetDispatchStageTimestamp(
EventMetrics::DispatchStage::kGenerated);
std::unique_ptr<EventMetrics> metrics_3 = CreateScrollUpdateEventMetrics(
ui::ScrollInputType::kWheel, true,
ScrollUpdateEventMetrics::ScrollUpdateType::kContinued,
EventMetrics::TraceId(789));
std::unique_ptr<EventMetrics> non_scroll_event = CreateEventMetrics(
ui::EventType::kTouchPressed, EventMetrics::TraceId(1000));
base::TimeDelta vsync_interval = event2_generation_ts - event1_generation_ts;
args_.interval = vsync_interval;
base::TimeTicks first_begin_frame_ts = test_tick_clock_.NowTicks();
SimulateBeginImplFrame();
reporting_controller_.OnFinishImplFrame(current_id_,
true);
EventMetrics::List metrics_list_1;
metrics_list_1.push_back(std::move(metrics_1));
SimulateSubmitCompositorFrame({{}, std::move(metrics_list_1), {}});
viz::FrameTimingDetails details_1 = {};
details_1.presentation_feedback.timestamp =
first_begin_frame_ts + 2 * vsync_interval;
reporting_controller_.DidPresentCompositorFrame(*current_token_,
details_1);
SimulateBeginImplFrame();
reporting_controller_.OnFinishImplFrame(current_id_,
true);
EventMetrics::List metrics_list_2;
metrics_list_2.push_back(std::move(metrics_2));
SimulateSubmitCompositorFrame({{}, std::move(metrics_list_2), {}});
viz::FrameTimingDetails details_2 = {};
details_2.presentation_feedback.timestamp =
first_begin_frame_ts + 4 * vsync_interval;
reporting_controller_.DidPresentCompositorFrame(*current_token_,
details_2);
SimulateBeginImplFrame();
reporting_controller_.OnFinishImplFrame(current_id_,
true);
EventMetrics::List metrics_list_3;
metrics_list_3.push_back(std::move(metrics_3));
SimulateSubmitCompositorFrame({{}, std::move(metrics_list_3), {}});
viz::FrameTimingDetails details_3 = {};
details_3.presentation_feedback.timestamp =
first_begin_frame_ts + 5 * vsync_interval;
reporting_controller_.DidPresentCompositorFrame(*current_token_,
details_3);
SimulateBeginImplFrame();
reporting_controller_.OnFinishImplFrame(current_id_,
true);
EventMetrics::List metrics_list_4;
metrics_list_4.push_back(std::move(non_scroll_event));
SimulateSubmitCompositorFrame({{}, std::move(metrics_list_4), {}});
viz::FrameTimingDetails details_4 = {};
details_4.presentation_feedback.timestamp =
first_begin_frame_ts + 6 * vsync_interval;
reporting_controller_.DidPresentCompositorFrame(*current_token_,
details_4);
absl::Status status = ttp.StopAndParseTrace();
ASSERT_TRUE(status.ok()) << status.message();
auto result = ttp.RunQuery(kScrollJankMetricArgsQuery);
ASSERT_TRUE(result.has_value()) << result.error();
EXPECT_THAT(result.value(), ::testing::ElementsAreArray(
base::test::TestTraceProcessor::QueryResult{
{"is_janky", "is_janky_v4"},
{"0", "0"},
{"1", "1"},
{"0", "0"},
{"[NULL]", "[NULL]"},
}));
}
Test if the new v4 metric logic identifies scroll jank in a scenario where a
frame is throttled.
vsync | | | | |
input GSU1 GSU2 GSU3
| | |
F1: |---------------|
F2: |---------------x (throttled)
F3: |--------------|
The new v4 metric should identify scroll jank because F2 got dropped even though
there was consistent input for a frame to have been generated.
*/
TEST_F(CompositorFrameReportingControllerTest, JankyThrottledScrolledFrame) {
base::test::TestTraceProcessor ttp;
ttp.StartTrace("input");
std::unique_ptr<EventMetrics> metrics_1 = CreateScrollUpdateEventMetrics(
ui::ScrollInputType::kWheel, false,
ScrollUpdateEventMetrics::ScrollUpdateType::kStarted,
EventMetrics::TraceId(123));
base::TimeTicks event1_generation_ts = metrics_1->GetDispatchStageTimestamp(
EventMetrics::DispatchStage::kGenerated);
std::unique_ptr<EventMetrics> metrics_2 = CreateScrollUpdateEventMetrics(
ui::ScrollInputType::kWheel, false,
ScrollUpdateEventMetrics::ScrollUpdateType::kContinued,
EventMetrics::TraceId(456));
base::TimeTicks event2_generation_ts = metrics_2->GetDispatchStageTimestamp(
EventMetrics::DispatchStage::kGenerated);
std::unique_ptr<EventMetrics> metrics_3 = CreateScrollUpdateEventMetrics(
ui::ScrollInputType::kWheel, false,
ScrollUpdateEventMetrics::ScrollUpdateType::kContinued,
EventMetrics::TraceId(789));
base::TimeDelta vsync_interval = event2_generation_ts - event1_generation_ts;
args_.interval = vsync_interval;
base::TimeTicks first_begin_frame_ts = test_tick_clock_.NowTicks();
SimulateBeginImplFrame();
reporting_controller_.OnFinishImplFrame(current_id_,
true);
EventMetrics::List metrics_list_1;
metrics_list_1.push_back(std::move(metrics_1));
SimulateSubmitCompositorFrame({{}, std::move(metrics_list_1), {}});
viz::FrameTimingDetails details_1 = {};
details_1.presentation_feedback.timestamp =
first_begin_frame_ts + 2 * vsync_interval;
reporting_controller_.DidPresentCompositorFrame(*current_token_,
details_1);
SimulateBeginImplFrame();
reporting_controller_.OnFinishImplFrame(current_id_,
true);
AdvanceNowByMs(10);
reporting_controller_.DidNotProduceFrame(current_id_,
FrameSkippedReason::kDrawThrottled);
SimulateBeginImplFrame();
reporting_controller_.OnFinishImplFrame(current_id_,
true);
EventMetrics::List metrics_list_3;
metrics_list_3.push_back(std::move(metrics_2));
metrics_list_3.push_back(std::move(metrics_3));
SimulateSubmitCompositorFrame({{}, std::move(metrics_list_3), {}});
viz::FrameTimingDetails details_3 = {};
details_3.presentation_feedback.timestamp =
first_begin_frame_ts + 4 * vsync_interval;
reporting_controller_.DidPresentCompositorFrame(*current_token_,
details_3);
absl::Status status = ttp.StopAndParseTrace();
ASSERT_TRUE(status.ok()) << status.message();
auto result = ttp.RunQuery(kScrollJankMetricArgsQuery);
ASSERT_TRUE(result.has_value()) << result.error();
EXPECT_THAT(result.value(), ::testing::ElementsAreArray(
base::test::TestTraceProcessor::QueryResult{
{"is_janky", "is_janky_v4"},
{"0", "0"},
{"[NULL]", "1"},
{"0", "[NULL]"},
}));
}
Test that the controller emits both the v1 and v4 per-scroll jank metrics. It
should emit v1 metrics when it encounters the next first gesture scroll update
event. It should emit v4 metrics when it encounters a gestures scroll end event.
vsync | | | | | | |
input GSU1 GSU2 GSE FGSU3 |
| | | | |
F1: |---------------| | |
F2: |---------------| |
F3: |---------------x (throttled) |
F4: | -------| |
F5: |-----------------------|
^ ^
| |
| v1 metrics emitted
v4 metrics emitted
*/
TEST_F(CompositorFrameReportingControllerTest, EmitsPerScrollJankMetrics) {
std::unique_ptr<EventMetrics> scroll_update1_metrics =
CreateScrollUpdateEventMetrics(
ui::ScrollInputType::kWheel, false,
ScrollUpdateEventMetrics::ScrollUpdateType::kStarted, std::nullopt);
base::TimeTicks scroll_update1_generation_ts =
scroll_update1_metrics->GetDispatchStageTimestamp(
EventMetrics::DispatchStage::kGenerated);
std::unique_ptr<EventMetrics> scroll_update2_metrics =
CreateScrollUpdateEventMetrics(
ui::ScrollInputType::kWheel, false,
ScrollUpdateEventMetrics::ScrollUpdateType::kContinued, std::nullopt);
base::TimeTicks scroll_update2_generation_ts =
scroll_update2_metrics->GetDispatchStageTimestamp(
EventMetrics::DispatchStage::kGenerated);
std::unique_ptr<EventMetrics> scroll_end_metrics =
CreateScrollEndEventMetrics(ui::ScrollInputType::kWheel,
false);
std::unique_ptr<EventMetrics> scroll_update3_metrics =
CreateScrollUpdateEventMetrics(
ui::ScrollInputType::kWheel, false,
ScrollUpdateEventMetrics::ScrollUpdateType::kStarted, std::nullopt);
base::TimeDelta vsync_interval =
scroll_update2_generation_ts - scroll_update1_generation_ts;
args_.interval = vsync_interval;
base::TimeTicks first_begin_frame_ts = test_tick_clock_.NowTicks();
{
base::HistogramTester histogram_tester;
SimulateBeginImplFrame();
reporting_controller_.OnFinishImplFrame(current_id_,
true);
EventMetrics::List metrics_list_1;
metrics_list_1.push_back(std::move(scroll_update1_metrics));
SimulateSubmitCompositorFrame({{}, std::move(metrics_list_1), {}});
viz::FrameTimingDetails details_1 = {};
details_1.presentation_feedback.timestamp =
first_begin_frame_ts + 2 * vsync_interval;
reporting_controller_.DidPresentCompositorFrame(*current_token_,
details_1);
SimulateBeginImplFrame();
reporting_controller_.OnFinishImplFrame(current_id_,
true);
EventMetrics::List metrics_list_2;
metrics_list_2.push_back(std::move(scroll_update2_metrics));
SimulateSubmitCompositorFrame({{}, std::move(metrics_list_2), {}});
viz::FrameTimingDetails details_2 = {};
details_2.presentation_feedback.timestamp =
first_begin_frame_ts + 3 * vsync_interval;
reporting_controller_.DidPresentCompositorFrame(*current_token_,
details_2);
SimulateBeginImplFrame();
reporting_controller_.OnFinishImplFrame(current_id_,
true);
AdvanceNowByMs(10);
reporting_controller_.DidNotProduceFrame(
current_id_, FrameSkippedReason::kDrawThrottled);
SimulateBeginImplFrame();
reporting_controller_.OnFinishImplFrame(current_id_,
true);
EventMetrics::List metrics_list_4;
metrics_list_4.push_back(std::move(scroll_end_metrics));
SimulateSubmitCompositorFrame({{}, std::move(metrics_list_4), {}});
viz::FrameTimingDetails details_4 = {};
details_4.presentation_feedback.timestamp =
first_begin_frame_ts + 5 * vsync_interval;
reporting_controller_.DidPresentCompositorFrame(*current_token_,
details_4);
histogram_tester.ExpectTotalCount(
"Event.ScrollJank.DelayedFramesPercentage.PerScroll", 0);
histogram_tester.ExpectTotalCount(
"Event.ScrollJank.DelayedFramesPercentage4.PerScroll", 1);
}
{
base::HistogramTester histogram_tester;
SimulateBeginImplFrame();
reporting_controller_.OnFinishImplFrame(current_id_,
true);
EventMetrics::List metrics_list_5;
metrics_list_5.push_back(std::move(scroll_update3_metrics));
SimulateSubmitCompositorFrame({{}, std::move(metrics_list_5), {}});
viz::FrameTimingDetails details_5 = {};
details_5.presentation_feedback.timestamp =
first_begin_frame_ts + 6 * vsync_interval;
reporting_controller_.DidPresentCompositorFrame(*current_token_,
details_5);
histogram_tester.ExpectTotalCount(
"Event.ScrollJank.DelayedFramesPercentage.PerScroll", 1);
histogram_tester.ExpectTotalCount(
"Event.ScrollJank.DelayedFramesPercentage4.PerScroll", 0);
}
}
TEST_F(CompositorFrameReportingControllerTest, VsyncIntervalArg) {
base::test::TestTraceProcessor ttp;
ttp.StartTrace("input");
std::unique_ptr<EventMetrics> metrics_1 = CreateScrollUpdateEventMetrics(
ui::ScrollInputType::kWheel, false,
ScrollUpdateEventMetrics::ScrollUpdateType::kStarted, std::nullopt);
std::unique_ptr<EventMetrics> metrics_2 = CreateScrollUpdateEventMetrics(
ui::ScrollInputType::kWheel, false,
ScrollUpdateEventMetrics::ScrollUpdateType::kContinued, std::nullopt);
std::unique_ptr<EventMetrics> non_scroll_event =
CreateEventMetrics(ui::EventType::kTouchPressed, std::nullopt);
args_.interval = base::Milliseconds(32);
SimulateBeginImplFrame();
reporting_controller_.OnFinishImplFrame(current_id_,
true);
EventMetrics::List metrics_list_1;
metrics_list_1.push_back(std::move(metrics_1));
SimulateSubmitCompositorFrame({{}, std::move(metrics_list_1), {}});
SimulatePresentCompositorFrame();
args_.interval = base::Milliseconds(8);
SimulateBeginImplFrame();
reporting_controller_.OnFinishImplFrame(current_id_,
true);
EventMetrics::List metrics_list_2;
metrics_list_2.push_back(std::move(metrics_2));
SimulateSubmitCompositorFrame({{}, std::move(metrics_list_2), {}});
SimulatePresentCompositorFrame();
absl::Status status = ttp.StopAndParseTrace();
ASSERT_TRUE(status.ok()) << status.message();
constexpr char kQuery[] =
R"(
SELECT
EXTRACT_ARG(slice.arg_set_id, 'event_latency.vsync_interval_ms') AS interval, COUNT(*) AS cnt
FROM slice
WHERE name = 'EventLatency'
GROUP BY 1
ORDER BY 1 ASC
)";
auto result = ttp.RunQuery(kQuery);
ASSERT_TRUE(result.has_value()) << result.error();
EXPECT_THAT(result.value(), ::testing::ElementsAre(
std::vector<std::string>{"interval", "cnt"},
std::vector<std::string>{"8", "1"},
std::vector<std::string>{"32", "1"}));
}
}
}