diff options
author | Allan Sandfeld Jensen <allan.jensen@qt.io> | 2022-09-29 16:16:15 +0200 |
---|---|---|
committer | Allan Sandfeld Jensen <allan.jensen@qt.io> | 2022-11-09 10:04:06 +0000 |
commit | a95a7417ad456115a1ef2da4bb8320531c0821f1 (patch) | |
tree | edcd59279e486d2fd4a8f88a7ed025bcf925c6e6 /chromium/cc/metrics/compositor_frame_reporter_unittest.cc | |
parent | 33fc33aa94d4add0878ec30dc818e34e1dd3cc2a (diff) |
BASELINE: Update Chromium to 106.0.5249.126
Change-Id: Ib0bb21c437a7d1686e21c33f2d329f2ac425b7ab
Reviewed-on: https://codereview.qt-project.org/c/qt/qtwebengine-chromium/+/438936
Reviewed-by: Allan Sandfeld Jensen <allan.jensen@qt.io>
Diffstat (limited to 'chromium/cc/metrics/compositor_frame_reporter_unittest.cc')
-rw-r--r-- | chromium/cc/metrics/compositor_frame_reporter_unittest.cc | 1522 |
1 files changed, 1478 insertions, 44 deletions
diff --git a/chromium/cc/metrics/compositor_frame_reporter_unittest.cc b/chromium/cc/metrics/compositor_frame_reporter_unittest.cc index 014a1a4a3f3..105435c5696 100644 --- a/chromium/cc/metrics/compositor_frame_reporter_unittest.cc +++ b/chromium/cc/metrics/compositor_frame_reporter_unittest.cc @@ -32,12 +32,12 @@ using ::testing::NotNull; class CompositorFrameReporterTest : public testing::Test { public: CompositorFrameReporterTest() : pipeline_reporter_(CreatePipelineReporter()) { - AdvanceNowByMs(1); + AdvanceNowByUs(1); dropped_frame_counter_.set_total_counter(&total_frame_counter_); } protected: - base::TimeTicks AdvanceNowByMs(int advance_ms) { + base::TimeTicks AdvanceNowByUs(int advance_ms) { test_tick_clock_.Advance(base::Microseconds(advance_ms)); return test_tick_clock_.NowTicks(); } @@ -57,44 +57,86 @@ class CompositorFrameReporterTest : public testing::Test { breakdown->update_layers = base::Microseconds(1); // Advance now by the sum of the breakdowns. - AdvanceNowByMs(10 + 9 + 8 + 7 + 6 + 5 + 3 + 2 + 1); + AdvanceNowByUs(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); + viz_breakdown.received_compositor_frame_timestamp = AdvanceNowByUs(1); + viz_breakdown.draw_start_timestamp = AdvanceNowByUs(2); + viz_breakdown.swap_timings.swap_start = AdvanceNowByUs(3); + viz_breakdown.swap_timings.swap_end = AdvanceNowByUs(4); + viz_breakdown.presentation_feedback.timestamp = AdvanceNowByUs(5); return viz_breakdown; } std::unique_ptr<EventMetrics> SetupEventMetrics( std::unique_ptr<EventMetrics> metrics) { if (metrics) { - AdvanceNowByMs(3); + AdvanceNowByUs(3); metrics->SetDispatchStageTimestamp( EventMetrics::DispatchStage::kRendererCompositorStarted); - AdvanceNowByMs(3); + AdvanceNowByUs(3); metrics->SetDispatchStageTimestamp( EventMetrics::DispatchStage::kRendererCompositorFinished); } return metrics; } + // Sets up the dispatch durations of each EventMetrics according to + // stage_durations. Stages with a duration of -1 will be skipped. + std::unique_ptr<EventMetrics> SetupEventMetricsWithDispatchTimes( + std::unique_ptr<EventMetrics> metrics, + const std::vector<int>& stage_durations) { + if (metrics) { + int num_stages = stage_durations.size(); + // Start indexing from 1 because the 0th index held duration from + // kGenerated to kArrivedInRendererCompositor, which was already used in + // when the EventMetrics was created. + for (int i = 1; i < num_stages; i++) { + if (stage_durations[i] >= 0) { + AdvanceNowByUs(stage_durations[i]); + metrics->SetDispatchStageTimestamp( + EventMetrics::DispatchStage(i + 1)); + } + } + } + return metrics; + } + std::unique_ptr<EventMetrics> CreateEventMetrics(ui::EventType type) { - const base::TimeTicks event_time = AdvanceNowByMs(3); - AdvanceNowByMs(3); + const base::TimeTicks event_time = AdvanceNowByUs(3); + AdvanceNowByUs(3); return SetupEventMetrics( EventMetrics::CreateForTesting(type, event_time, &test_tick_clock_)); } + // Creates EventMetrics with elements in stage_durations representing each + // dispatch stage's desired duration respectively, with the 0th index + // representing the duration from kGenerated to kArrivedInRendererCompositor. + // stage_durations must have at least 1 element for the first required stage + // Use -1 for stages that want to be skipped. + std::unique_ptr<EventMetrics> CreateScrollUpdateEventMetricsWithDispatchTimes( + bool is_inertial, + ScrollUpdateEventMetrics::ScrollUpdateType scroll_update_type, + const std::vector<int>& stage_durations) { + DCHECK_GT((int)stage_durations.size(), 0); + const base::TimeTicks event_time = AdvanceNowByUs(3); + AdvanceNowByUs(stage_durations[0]); + // Creates a kGestureScrollUpdate event. + return SetupEventMetricsWithDispatchTimes( + ScrollUpdateEventMetrics::CreateForTesting( + ui::ET_GESTURE_SCROLL_UPDATE, ui::ScrollInputType::kWheel, + is_inertial, scroll_update_type, /*delta=*/10.0f, event_time, + &test_tick_clock_), + stage_durations); + } + std::unique_ptr<EventMetrics> CreateScrollBeginMetrics() { - const base::TimeTicks event_time = AdvanceNowByMs(3); - AdvanceNowByMs(3); + const base::TimeTicks event_time = AdvanceNowByUs(3); + AdvanceNowByUs(3); return SetupEventMetrics(ScrollEventMetrics::CreateForTesting( ui::ET_GESTURE_SCROLL_BEGIN, ui::ScrollInputType::kWheel, /*is_inertial=*/false, event_time, &test_tick_clock_)); @@ -103,8 +145,8 @@ class CompositorFrameReporterTest : public testing::Test { std::unique_ptr<EventMetrics> CreateScrollUpdateEventMetrics( bool is_inertial, ScrollUpdateEventMetrics::ScrollUpdateType scroll_update_type) { - const base::TimeTicks event_time = AdvanceNowByMs(3); - AdvanceNowByMs(3); + const base::TimeTicks event_time = AdvanceNowByUs(3); + AdvanceNowByUs(3); return SetupEventMetrics(ScrollUpdateEventMetrics::CreateForTesting( ui::ET_GESTURE_SCROLL_UPDATE, ui::ScrollInputType::kWheel, is_inertial, scroll_update_type, /*delta=*/10.0f, event_time, &test_tick_clock_)); @@ -113,8 +155,8 @@ class CompositorFrameReporterTest : public testing::Test { std::unique_ptr<EventMetrics> CreatePinchEventMetrics( ui::EventType type, ui::ScrollInputType input_type) { - const base::TimeTicks event_time = AdvanceNowByMs(3); - AdvanceNowByMs(3); + const base::TimeTicks event_time = AdvanceNowByUs(3); + AdvanceNowByUs(3); return SetupEventMetrics(PinchEventMetrics::CreateForTesting( type, input_type, event_time, &test_tick_clock_)); } @@ -144,6 +186,28 @@ class CompositorFrameReporterTest : public testing::Test { return reporter; } + void IntToTimeDeltaVector(std::vector<base::TimeDelta>& timedelta_vector, + std::vector<int> int_vector) { + size_t vector_size = int_vector.size(); + for (size_t i = 0; i < vector_size; i++) { + timedelta_vector[i] = base::Microseconds(int_vector[i]); + } + } + + void VerifyLatencyInfo( + CompositorFrameReporter::CompositorLatencyInfo& expected_info, + CompositorFrameReporter::CompositorLatencyInfo& actual_info) { + EXPECT_EQ(expected_info.top_level_stages, actual_info.top_level_stages); + EXPECT_EQ(expected_info.blink_breakdown_stages, + actual_info.blink_breakdown_stages); + EXPECT_EQ(expected_info.viz_breakdown_stages, + actual_info.viz_breakdown_stages); + EXPECT_EQ(expected_info.total_latency, actual_info.total_latency); + EXPECT_EQ(expected_info.total_blink_latency, + actual_info.total_blink_latency); + EXPECT_EQ(expected_info.total_viz_latency, actual_info.total_viz_latency); + } + // This should be defined before |pipeline_reporter_| so it is created before // and destroyed after that. base::SimpleTestTickClock test_tick_clock_; @@ -151,6 +215,14 @@ class CompositorFrameReporterTest : public testing::Test { DroppedFrameCounter dropped_frame_counter_; TotalFrameCounter total_frame_counter_; std::unique_ptr<CompositorFrameReporter> pipeline_reporter_; + + // Number of breakdown stages of the current PipelineReporter + const int kNumOfCompositorStages = + static_cast<int>(CompositorFrameReporter::StageType::kStageTypeCount) - 1; + const int kNumDispatchStages = + static_cast<int>(EventMetrics::DispatchStage::kMaxValue); + const base::TimeDelta kLatencyPredictionDeviationThreshold = + base::Milliseconds(8.33); }; TEST_F(CompositorFrameReporterTest, MainFrameAbortedReportingTest) { @@ -161,25 +233,25 @@ TEST_F(CompositorFrameReporterTest, MainFrameAbortedReportingTest) { Now()); EXPECT_EQ(0u, pipeline_reporter_->stage_history_size_for_testing()); - AdvanceNowByMs(3); + AdvanceNowByUs(3); pipeline_reporter_->StartStage( CompositorFrameReporter::StageType::kSendBeginMainFrameToCommit, Now()); EXPECT_EQ(1u, pipeline_reporter_->stage_history_size_for_testing()); - AdvanceNowByMs(3); + AdvanceNowByUs(3); pipeline_reporter_->StartStage( CompositorFrameReporter::StageType::kEndActivateToSubmitCompositorFrame, Now()); EXPECT_EQ(2u, pipeline_reporter_->stage_history_size_for_testing()); - AdvanceNowByMs(3); + AdvanceNowByUs(3); pipeline_reporter_->StartStage( CompositorFrameReporter::StageType:: kSubmitCompositorFrameToPresentationCompositorFrame, Now()); EXPECT_EQ(3u, pipeline_reporter_->stage_history_size_for_testing()); - AdvanceNowByMs(3); + AdvanceNowByUs(3); pipeline_reporter_->TerminateFrame( CompositorFrameReporter::FrameTerminationStatus::kPresentedFrame, Now()); EXPECT_EQ(4u, pipeline_reporter_->stage_history_size_for_testing()); @@ -206,12 +278,12 @@ TEST_F(CompositorFrameReporterTest, ReplacedByNewReporterReportingTest) { Now()); EXPECT_EQ(0u, pipeline_reporter_->stage_history_size_for_testing()); - AdvanceNowByMs(3); + AdvanceNowByUs(3); pipeline_reporter_->StartStage( CompositorFrameReporter::StageType::kEndCommitToActivation, Now()); EXPECT_EQ(1u, pipeline_reporter_->stage_history_size_for_testing()); - AdvanceNowByMs(2); + AdvanceNowByUs(2); pipeline_reporter_->TerminateFrame( CompositorFrameReporter::FrameTerminationStatus::kReplacedByNewReporter, Now()); @@ -230,13 +302,13 @@ TEST_F(CompositorFrameReporterTest, SubmittedFrameReportingTest) { CompositorFrameReporter::StageType::kActivation, Now()); EXPECT_EQ(0u, pipeline_reporter_->stage_history_size_for_testing()); - AdvanceNowByMs(3); + AdvanceNowByUs(3); pipeline_reporter_->StartStage( CompositorFrameReporter::StageType::kEndActivateToSubmitCompositorFrame, Now()); EXPECT_EQ(1u, pipeline_reporter_->stage_history_size_for_testing()); - AdvanceNowByMs(2); + AdvanceNowByUs(2); pipeline_reporter_->TerminateFrame( CompositorFrameReporter::FrameTerminationStatus::kPresentedFrame, Now()); EXPECT_EQ(2u, pipeline_reporter_->stage_history_size_for_testing()); @@ -266,12 +338,12 @@ TEST_F(CompositorFrameReporterTest, SubmittedDroppedFrameReportingTest) { CompositorFrameReporter::StageType::kSendBeginMainFrameToCommit, Now()); EXPECT_EQ(0u, pipeline_reporter_->stage_history_size_for_testing()); - AdvanceNowByMs(3); + AdvanceNowByUs(3); pipeline_reporter_->StartStage(CompositorFrameReporter::StageType::kCommit, Now()); EXPECT_EQ(1u, pipeline_reporter_->stage_history_size_for_testing()); - AdvanceNowByMs(2); + AdvanceNowByUs(2); pipeline_reporter_->TerminateFrame( CompositorFrameReporter::FrameTerminationStatus::kDidNotPresentFrame, Now()); @@ -313,24 +385,24 @@ TEST_F(CompositorFrameReporterTest, std::make_move_iterator(std::end(event_metrics_ptrs))); std::vector<base::TimeTicks> event_times = GetEventTimestamps(events_metrics); - AdvanceNowByMs(3); + AdvanceNowByUs(3); pipeline_reporter_->StartStage( CompositorFrameReporter::StageType::kBeginImplFrameToSendBeginMainFrame, Now()); - AdvanceNowByMs(3); + AdvanceNowByUs(3); pipeline_reporter_->StartStage( CompositorFrameReporter::StageType::kEndActivateToSubmitCompositorFrame, Now()); - AdvanceNowByMs(3); + AdvanceNowByUs(3); pipeline_reporter_->StartStage( CompositorFrameReporter::StageType:: kSubmitCompositorFrameToPresentationCompositorFrame, Now()); pipeline_reporter_->AddEventsMetrics(std::move(events_metrics)); - const base::TimeTicks presentation_time = AdvanceNowByMs(3); + const base::TimeTicks presentation_time = AdvanceNowByUs(3); pipeline_reporter_->TerminateFrame( CompositorFrameReporter::FrameTerminationStatus::kPresentedFrame, presentation_time); @@ -405,24 +477,24 @@ TEST_F(CompositorFrameReporterTest, std::make_move_iterator(std::end(event_metrics_ptrs))); std::vector<base::TimeTicks> event_times = GetEventTimestamps(events_metrics); - AdvanceNowByMs(3); + AdvanceNowByUs(3); pipeline_reporter_->StartStage( CompositorFrameReporter::StageType::kBeginImplFrameToSendBeginMainFrame, Now()); - AdvanceNowByMs(3); + AdvanceNowByUs(3); pipeline_reporter_->StartStage( CompositorFrameReporter::StageType::kEndActivateToSubmitCompositorFrame, Now()); - AdvanceNowByMs(3); + AdvanceNowByUs(3); pipeline_reporter_->StartStage( CompositorFrameReporter::StageType:: kSubmitCompositorFrameToPresentationCompositorFrame, Now()); pipeline_reporter_->AddEventsMetrics(std::move(events_metrics)); - AdvanceNowByMs(3); + AdvanceNowByUs(3); viz::FrameTimingDetails viz_breakdown = BuildVizBreakdown(); pipeline_reporter_->SetVizBreakdown(viz_breakdown); pipeline_reporter_->TerminateFrame( @@ -493,24 +565,24 @@ TEST_F(CompositorFrameReporterTest, std::make_move_iterator(std::end(event_metrics_ptrs))); std::vector<base::TimeTicks> event_times = GetEventTimestamps(events_metrics); - AdvanceNowByMs(3); + AdvanceNowByUs(3); pipeline_reporter_->StartStage( CompositorFrameReporter::StageType::kBeginImplFrameToSendBeginMainFrame, Now()); - AdvanceNowByMs(3); + AdvanceNowByUs(3); pipeline_reporter_->StartStage( CompositorFrameReporter::StageType::kEndActivateToSubmitCompositorFrame, Now()); - AdvanceNowByMs(3); + AdvanceNowByUs(3); pipeline_reporter_->StartStage( CompositorFrameReporter::StageType:: kSubmitCompositorFrameToPresentationCompositorFrame, Now()); pipeline_reporter_->AddEventsMetrics(std::move(events_metrics)); - AdvanceNowByMs(3); + AdvanceNowByUs(3); viz::FrameTimingDetails viz_breakdown = BuildVizBreakdown(); pipeline_reporter_->SetVizBreakdown(viz_breakdown); pipeline_reporter_->TerminateFrame( @@ -575,24 +647,24 @@ TEST_F(CompositorFrameReporterTest, std::make_move_iterator(std::begin(event_metrics_ptrs)), std::make_move_iterator(std::end(event_metrics_ptrs))); - AdvanceNowByMs(3); + AdvanceNowByUs(3); pipeline_reporter_->StartStage( CompositorFrameReporter::StageType::kBeginImplFrameToSendBeginMainFrame, Now()); - AdvanceNowByMs(3); + AdvanceNowByUs(3); pipeline_reporter_->StartStage( CompositorFrameReporter::StageType::kEndActivateToSubmitCompositorFrame, Now()); - AdvanceNowByMs(3); + AdvanceNowByUs(3); pipeline_reporter_->StartStage( CompositorFrameReporter::StageType:: kSubmitCompositorFrameToPresentationCompositorFrame, Now()); pipeline_reporter_->AddEventsMetrics(std::move(events_metrics)); - AdvanceNowByMs(3); + AdvanceNowByUs(3); pipeline_reporter_->TerminateFrame( CompositorFrameReporter::FrameTerminationStatus::kDidNotPresentFrame, Now()); @@ -720,5 +792,1367 @@ TEST_F(CompositorFrameReporterTest, PartialUpdateDependentQueues) { pipeline_reporter_->owned_partial_update_dependents_size_for_testing()); } +TEST_F(CompositorFrameReporterTest, StageLatencyGeneralPrediction) { + pipeline_reporter_->StartStage( + CompositorFrameReporter::StageType::kBeginImplFrameToSendBeginMainFrame, + Now()); + + AdvanceNowByUs(3); + pipeline_reporter_->StartStage( + CompositorFrameReporter::StageType::kSendBeginMainFrameToCommit, Now()); + AdvanceNowByUs(4); + base::TimeTicks begin_main_frame_start_time = Now(); + std::unique_ptr<BeginMainFrameMetrics> blink_breakdown = + BuildBlinkBreakdown(); + pipeline_reporter_->SetBlinkBreakdown(std::move(blink_breakdown), + begin_main_frame_start_time); + + pipeline_reporter_->StartStage(CompositorFrameReporter::StageType::kCommit, + Now()); + + AdvanceNowByUs(3); + pipeline_reporter_->StartStage( + CompositorFrameReporter::StageType::kEndCommitToActivation, Now()); + + AdvanceNowByUs(3); + pipeline_reporter_->StartStage( + CompositorFrameReporter::StageType::kActivation, Now()); + + AdvanceNowByUs(3); + pipeline_reporter_->StartStage( + CompositorFrameReporter::StageType::kEndActivateToSubmitCompositorFrame, + Now()); + + AdvanceNowByUs(3); + pipeline_reporter_->StartStage( + CompositorFrameReporter::StageType:: + kSubmitCompositorFrameToPresentationCompositorFrame, + Now()); + viz::FrameTimingDetails viz_breakdown = BuildVizBreakdown(); + pipeline_reporter_->SetVizBreakdown(viz_breakdown); + + pipeline_reporter_->TerminateFrame( + CompositorFrameReporter::FrameTerminationStatus::kPresentedFrame, + viz_breakdown.presentation_feedback.timestamp); + + // predictions when this is the very first prediction + CompositorFrameReporter::CompositorLatencyInfo expected_latency_predictions1; + expected_latency_predictions1.top_level_stages = { + base::Microseconds(3), base::Microseconds(55), base::Microseconds(3), + base::Microseconds(3), base::Microseconds(3), base::Microseconds(3), + base::Microseconds(15)}; + expected_latency_predictions1.blink_breakdown_stages = { + base::Microseconds(10), base::Microseconds(9), base::Microseconds(8), + base::Microseconds(7), base::Microseconds(0), base::Microseconds(5), + base::Microseconds(6), base::Microseconds(3), base::Microseconds(2), + base::Microseconds(1), base::Microseconds(4)}; + expected_latency_predictions1.viz_breakdown_stages = { + base::Microseconds(1), base::Microseconds(2), base::Microseconds(3), + base::Microseconds(4), base::Microseconds(5), base::Microseconds(0), + base::Microseconds(0), base::Microseconds(0), base::Microseconds(0)}; + expected_latency_predictions1.total_latency = base::Microseconds(85); + expected_latency_predictions1.total_blink_latency = base::Microseconds(55); + expected_latency_predictions1.total_viz_latency = base::Microseconds(15); + + // predictions when there exists a previous prediction + CompositorFrameReporter::CompositorLatencyInfo expected_latency_predictions2( + base::Microseconds(0)); + expected_latency_predictions2.top_level_stages = { + base::Microseconds(1), base::Microseconds(13), base::Microseconds(3), + base::Microseconds(0), base::Microseconds(2), base::Microseconds(3), + base::Microseconds(3)}; + expected_latency_predictions2.blink_breakdown_stages = { + base::Microseconds(10), base::Microseconds(9), base::Microseconds(8), + base::Microseconds(7), base::Microseconds(0), base::Microseconds(5), + base::Microseconds(6), base::Microseconds(3), base::Microseconds(2), + base::Microseconds(1), base::Microseconds(4)}; + expected_latency_predictions2.viz_breakdown_stages = { + base::Microseconds(1), base::Microseconds(2), base::Microseconds(3), + base::Microseconds(4), base::Microseconds(5), base::Microseconds(0), + base::Microseconds(0), base::Microseconds(0), base::Microseconds(0)}; + expected_latency_predictions2.total_latency = base::Microseconds(28); + expected_latency_predictions2.total_blink_latency = base::Microseconds(55); + expected_latency_predictions2.total_viz_latency = base::Microseconds(15); + + // expected attribution for all 3 cases above + std::vector<std::string> expected_latency_attributions = {}; + + CompositorFrameReporter::CompositorLatencyInfo actual_latency_predictions1( + base::Microseconds(-1)); + pipeline_reporter_->CalculateCompositorLatencyPrediction( + actual_latency_predictions1, kLatencyPredictionDeviationThreshold); + std::vector<std::string> actual_latency_attributions1 = + pipeline_reporter_->high_latency_substages_for_testing(); + pipeline_reporter_->ClearHighLatencySubstagesForTesting(); + + CompositorFrameReporter::CompositorLatencyInfo actual_latency_predictions2( + base::Microseconds(0)); + actual_latency_predictions2.top_level_stages = { + base::Microseconds(1), base::Microseconds(0), base::Microseconds(4), + base::Microseconds(0), base::Microseconds(2), base::Microseconds(3), + base::Microseconds(0)}; + actual_latency_predictions2.total_latency = base::Microseconds(10); + pipeline_reporter_->CalculateCompositorLatencyPrediction( + actual_latency_predictions2, kLatencyPredictionDeviationThreshold); + std::vector<std::string> actual_latency_attributions2 = + pipeline_reporter_->high_latency_substages_for_testing(); + pipeline_reporter_->ClearHighLatencySubstagesForTesting(); + + VerifyLatencyInfo(expected_latency_predictions1, actual_latency_predictions1); + VerifyLatencyInfo(expected_latency_predictions2, actual_latency_predictions2); + + EXPECT_EQ(expected_latency_attributions, actual_latency_attributions1); + EXPECT_EQ(expected_latency_attributions, actual_latency_attributions2); + + pipeline_reporter_ = nullptr; +} + +TEST_F(CompositorFrameReporterTest, StageLatencyAllZeroPrediction) { + pipeline_reporter_->StartStage( + CompositorFrameReporter::StageType::kBeginImplFrameToSendBeginMainFrame, + Now()); + + AdvanceNowByUs(0); + pipeline_reporter_->StartStage( + CompositorFrameReporter::StageType::kSendBeginMainFrameToCommit, Now()); + + AdvanceNowByUs(0); + pipeline_reporter_->StartStage(CompositorFrameReporter::StageType::kCommit, + Now()); + + AdvanceNowByUs(0); + pipeline_reporter_->StartStage( + CompositorFrameReporter::StageType::kEndCommitToActivation, Now()); + + AdvanceNowByUs(0); + pipeline_reporter_->StartStage( + CompositorFrameReporter::StageType::kActivation, Now()); + + AdvanceNowByUs(0); + pipeline_reporter_->StartStage( + CompositorFrameReporter::StageType::kEndActivateToSubmitCompositorFrame, + Now()); + + AdvanceNowByUs(0); + pipeline_reporter_->StartStage( + CompositorFrameReporter::StageType:: + kSubmitCompositorFrameToPresentationCompositorFrame, + Now()); + + AdvanceNowByUs(0); + pipeline_reporter_->TerminateFrame( + CompositorFrameReporter::FrameTerminationStatus::kDidNotProduceFrame, + Now()); + + // predictions when this is the very first prediction + CompositorFrameReporter::CompositorLatencyInfo expected_latency_predictions1( + base::Microseconds(-1)); + + // predictions when there exists a previous prediction + CompositorFrameReporter::CompositorLatencyInfo expected_latency_predictions2( + base::Microseconds(0)); + expected_latency_predictions2.top_level_stages = { + base::Microseconds(1), base::Microseconds(0), base::Microseconds(4), + base::Microseconds(0), base::Microseconds(2), base::Microseconds(3), + base::Microseconds(0)}; + expected_latency_predictions2.total_latency = base::Microseconds(10); + + // expected attribution for all 3 cases above + std::vector<std::string> expected_latency_attributions = {}; + + CompositorFrameReporter::CompositorLatencyInfo actual_latency_predictions1( + base::Microseconds(-1)); + pipeline_reporter_->CalculateCompositorLatencyPrediction( + actual_latency_predictions1, kLatencyPredictionDeviationThreshold); + std::vector<std::string> actual_latency_attributions1 = + pipeline_reporter_->high_latency_substages_for_testing(); + pipeline_reporter_->ClearHighLatencySubstagesForTesting(); + + CompositorFrameReporter::CompositorLatencyInfo actual_latency_predictions2( + base::Microseconds(0)); + actual_latency_predictions2.top_level_stages = { + base::Microseconds(1), base::Microseconds(0), base::Microseconds(4), + base::Microseconds(0), base::Microseconds(2), base::Microseconds(3), + base::Microseconds(0)}; + actual_latency_predictions2.total_latency = base::Microseconds(10); + + pipeline_reporter_->CalculateCompositorLatencyPrediction( + actual_latency_predictions2, kLatencyPredictionDeviationThreshold); + std::vector<std::string> actual_latency_attributions2 = + pipeline_reporter_->high_latency_substages_for_testing(); + pipeline_reporter_->ClearHighLatencySubstagesForTesting(); + + VerifyLatencyInfo(expected_latency_predictions1, actual_latency_predictions1); + VerifyLatencyInfo(expected_latency_predictions2, actual_latency_predictions2); + + EXPECT_EQ(expected_latency_attributions, actual_latency_attributions1); + EXPECT_EQ(expected_latency_attributions, actual_latency_attributions2); + + pipeline_reporter_ = nullptr; +} + +TEST_F(CompositorFrameReporterTest, StageLatencyLargeDurationPrediction) { + pipeline_reporter_->StartStage( + CompositorFrameReporter::StageType::kBeginImplFrameToSendBeginMainFrame, + Now()); + + AdvanceNowByUs(10000000); + pipeline_reporter_->StartStage( + CompositorFrameReporter::StageType::kSendBeginMainFrameToCommit, Now()); + AdvanceNowByUs(400000); + base::TimeTicks begin_main_frame_start_time = Now(); + + auto blink_breakdown = std::make_unique<BeginMainFrameMetrics>(); + blink_breakdown->handle_input_events = base::Microseconds(1000000); + blink_breakdown->animate = base::Microseconds(900000); + blink_breakdown->style_update = base::Microseconds(800000); + blink_breakdown->layout_update = base::Microseconds(300000); + blink_breakdown->accessibility = base::Microseconds(400000); + blink_breakdown->prepaint = base::Microseconds(500000); + blink_breakdown->compositing_inputs = base::Microseconds(600000); + blink_breakdown->paint = base::Microseconds(300000); + blink_breakdown->composite_commit = base::Microseconds(200000); + blink_breakdown->update_layers = base::Microseconds(100000); + AdvanceNowByUs(5100000); + + pipeline_reporter_->SetBlinkBreakdown(std::move(blink_breakdown), + begin_main_frame_start_time); + + pipeline_reporter_->StartStage(CompositorFrameReporter::StageType::kCommit, + Now()); + + AdvanceNowByUs(6000000); + pipeline_reporter_->StartStage( + CompositorFrameReporter::StageType::kEndCommitToActivation, Now()); + + AdvanceNowByUs(10000000); + pipeline_reporter_->StartStage( + CompositorFrameReporter::StageType::kActivation, Now()); + + AdvanceNowByUs(0); + pipeline_reporter_->StartStage( + CompositorFrameReporter::StageType::kEndActivateToSubmitCompositorFrame, + Now()); + + AdvanceNowByUs(2000000); + pipeline_reporter_->StartStage( + CompositorFrameReporter::StageType:: + kSubmitCompositorFrameToPresentationCompositorFrame, + Now()); + + viz::FrameTimingDetails viz_breakdown; + viz_breakdown.received_compositor_frame_timestamp = AdvanceNowByUs(1000000); + viz_breakdown.draw_start_timestamp = AdvanceNowByUs(2000000); + viz_breakdown.swap_timings.swap_start = AdvanceNowByUs(3000000); + viz_breakdown.presentation_feedback.available_timestamp = + AdvanceNowByUs(15000000); + viz_breakdown.presentation_feedback.ready_timestamp = AdvanceNowByUs(700000); + viz_breakdown.presentation_feedback.latch_timestamp = AdvanceNowByUs(800000); + viz_breakdown.swap_timings.swap_end = AdvanceNowByUs(1000000); + viz_breakdown.presentation_feedback.timestamp = AdvanceNowByUs(5000000); + + pipeline_reporter_->SetVizBreakdown(viz_breakdown); + + pipeline_reporter_->TerminateFrame( + CompositorFrameReporter::FrameTerminationStatus::kPresentedFrame, Now()); + + // predictions when this is the very first prediction + CompositorFrameReporter::CompositorLatencyInfo expected_latency_predictions1; + expected_latency_predictions1.top_level_stages = { + base::Microseconds(10000000), base::Microseconds(5500000), + base::Microseconds(6000000), base::Microseconds(10000000), + base::Microseconds(0), base::Microseconds(2000000), + base::Microseconds(28500000)}; + expected_latency_predictions1.blink_breakdown_stages = { + base::Microseconds(1000000), base::Microseconds(900000), + base::Microseconds(800000), base::Microseconds(300000), + base::Microseconds(400000), base::Microseconds(500000), + base::Microseconds(600000), base::Microseconds(300000), + base::Microseconds(200000), base::Microseconds(100000), + base::Microseconds(400000)}; + expected_latency_predictions1.viz_breakdown_stages = { + base::Microseconds(1000000), base::Microseconds(2000000), + base::Microseconds(3000000), base::Microseconds(0), + base::Microseconds(5000000), base::Microseconds(15000000), + base::Microseconds(700000), base::Microseconds(800000), + base::Microseconds(1000000)}; + expected_latency_predictions1.total_latency = base::Microseconds(62000000); + expected_latency_predictions1.total_blink_latency = + base::Microseconds(5500000); + expected_latency_predictions1.total_viz_latency = + base::Microseconds(28500000); + + // predictions when there exists a previous prediction + CompositorFrameReporter::CompositorLatencyInfo expected_latency_predictions2; + expected_latency_predictions2.top_level_stages = { + base::Microseconds(8500000), base::Microseconds(4375000), + base::Microseconds(4875000), base::Microseconds(5252650), + base::Microseconds(750000), base::Microseconds(1850000), + base::Microseconds(18375000)}; + expected_latency_predictions2.blink_breakdown_stages = { + base::Microseconds(1000000), base::Microseconds(225000), + base::Microseconds(500000), base::Microseconds(75000), + base::Microseconds(250000), base::Microseconds(350000), + base::Microseconds(150000), base::Microseconds(750000), + base::Microseconds(650000), base::Microseconds(250000), + base::Microseconds(175000)}; + expected_latency_predictions2.viz_breakdown_stages = { + base::Microseconds(625000), base::Microseconds(875000), + base::Microseconds(1500000), base::Microseconds(0), + base::Microseconds(1706075), base::Microseconds(9750000), + base::Microseconds(925000), base::Microseconds(1100000), + base::Microseconds(1893925)}; + expected_latency_predictions2.total_latency = base::Microseconds(43977650); + expected_latency_predictions2.total_blink_latency = + base::Microseconds(4375000); + expected_latency_predictions2.total_viz_latency = + base::Microseconds(18375000); + + // expected attribution for cases 1 above + std::vector<std::string> expected_latency_attributions1 = {}; + + // expected attribution for case 2 above + std::vector<std::string> expected_latency_attributions2 = { + "EndCommitToActivation", + "SubmitCompositorFrameToPresentationCompositorFrame." + "SwapEndToPresentationCompositorFrame"}; + + CompositorFrameReporter::CompositorLatencyInfo actual_latency_predictions1( + base::Microseconds(-1)); + pipeline_reporter_->CalculateCompositorLatencyPrediction( + actual_latency_predictions1, kLatencyPredictionDeviationThreshold); + std::vector<std::string> actual_latency_attributions1 = + pipeline_reporter_->high_latency_substages_for_testing(); + pipeline_reporter_->ClearHighLatencySubstagesForTesting(); + + CompositorFrameReporter::CompositorLatencyInfo actual_latency_predictions2; + actual_latency_predictions2.top_level_stages = { + base::Microseconds(8000000), base::Microseconds(4000000), + base::Microseconds(4500000), base::Microseconds(3670200), + base::Microseconds(1000000), base::Microseconds(1800000), + base::Microseconds(15000000)}; + actual_latency_predictions2.blink_breakdown_stages = { + base::Microseconds(1000000), base::Microseconds(0), + base::Microseconds(400000), base::Microseconds(0), + base::Microseconds(200000), base::Microseconds(300000), + base::Microseconds(0), base::Microseconds(900000), + base::Microseconds(800000), base::Microseconds(300000), + base::Microseconds(100000)}; + actual_latency_predictions2.viz_breakdown_stages = { + base::Microseconds(500000), base::Microseconds(500000), + base::Microseconds(1000000), base::Microseconds(0), + base::Microseconds(608100), base::Microseconds(8000000), + base::Microseconds(1000000), base::Microseconds(1200000), + base::Microseconds(2191900)}; + actual_latency_predictions2.total_latency = base::Microseconds(37970200); + actual_latency_predictions2.total_blink_latency = base::Microseconds(4000000); + actual_latency_predictions2.total_viz_latency = base::Microseconds(15000000); + + pipeline_reporter_->CalculateCompositorLatencyPrediction( + actual_latency_predictions2, kLatencyPredictionDeviationThreshold); + std::vector<std::string> actual_latency_attributions2 = + pipeline_reporter_->high_latency_substages_for_testing(); + pipeline_reporter_->ClearHighLatencySubstagesForTesting(); + + VerifyLatencyInfo(expected_latency_predictions1, actual_latency_predictions1); + VerifyLatencyInfo(expected_latency_predictions2, actual_latency_predictions2); + + EXPECT_EQ(expected_latency_attributions1, actual_latency_attributions1); + EXPECT_EQ(expected_latency_attributions2, actual_latency_attributions2); + + pipeline_reporter_ = nullptr; +} + +TEST_F(CompositorFrameReporterTest, StageLatencyMultiplePrediction) { + CompositorFrameReporter::CompositorLatencyInfo actual_latency_predictions( + base::Microseconds(-1)); + CompositorFrameReporter::CompositorLatencyInfo expected_latency_predictions( + base::Microseconds(-1)); + + // First compositor reporter (general) + pipeline_reporter_->StartStage( + CompositorFrameReporter::StageType::kBeginImplFrameToSendBeginMainFrame, + Now()); + + AdvanceNowByUs(16000); + pipeline_reporter_->StartStage( + CompositorFrameReporter::StageType::kEndActivateToSubmitCompositorFrame, + Now()); + + AdvanceNowByUs(1500); + pipeline_reporter_->StartStage( + CompositorFrameReporter::StageType:: + kSubmitCompositorFrameToPresentationCompositorFrame, + Now()); + + viz::FrameTimingDetails viz_breakdown; + viz_breakdown.received_compositor_frame_timestamp = AdvanceNowByUs(330000); + viz_breakdown.draw_start_timestamp = AdvanceNowByUs(23000); + viz_breakdown.swap_timings.swap_start = AdvanceNowByUs(170000); + viz_breakdown.swap_timings.swap_end = AdvanceNowByUs(280000); + viz_breakdown.presentation_feedback.timestamp = AdvanceNowByUs(30000); + + pipeline_reporter_->SetVizBreakdown(viz_breakdown); + + pipeline_reporter_->TerminateFrame( + CompositorFrameReporter::FrameTerminationStatus::kPresentedFrame, Now()); + + expected_latency_predictions.top_level_stages = { + base::Microseconds(16000), base::Microseconds(0), + base::Microseconds(0), base::Microseconds(0), + base::Microseconds(0), base::Microseconds(1500), + base::Microseconds(833000)}; + expected_latency_predictions.blink_breakdown_stages = { + base::Microseconds(0), base::Microseconds(0), base::Microseconds(0), + base::Microseconds(0), base::Microseconds(0), base::Microseconds(0), + base::Microseconds(0), base::Microseconds(0), base::Microseconds(0), + base::Microseconds(0), base::Microseconds(0)}; + expected_latency_predictions.viz_breakdown_stages = { + base::Microseconds(330000), base::Microseconds(23000), + base::Microseconds(170000), base::Microseconds(280000), + base::Microseconds(30000), base::Microseconds(0), + base::Microseconds(0), base::Microseconds(0), + base::Microseconds(0)}; + expected_latency_predictions.total_latency = base::Microseconds(850500); + expected_latency_predictions.total_blink_latency = base::Microseconds(0); + expected_latency_predictions.total_viz_latency = base::Microseconds(833000); + + pipeline_reporter_->CalculateCompositorLatencyPrediction( + actual_latency_predictions, kLatencyPredictionDeviationThreshold); + + VerifyLatencyInfo(expected_latency_predictions, actual_latency_predictions); + + // Second compositor reporter (without subtmit stage) + pipeline_reporter_ = CreatePipelineReporter(); + pipeline_reporter_->StartStage( + CompositorFrameReporter::StageType::kBeginImplFrameToSendBeginMainFrame, + Now()); + + AdvanceNowByUs(16000); + pipeline_reporter_->TerminateFrame( + CompositorFrameReporter::FrameTerminationStatus::kDidNotProduceFrame, + Now()); + + expected_latency_predictions.top_level_stages = { + base::Microseconds(16000), base::Microseconds(0), + base::Microseconds(0), base::Microseconds(0), + base::Microseconds(0), base::Microseconds(1500), + base::Microseconds(833000)}; + expected_latency_predictions.blink_breakdown_stages = { + base::Microseconds(0), base::Microseconds(0), base::Microseconds(0), + base::Microseconds(0), base::Microseconds(0), base::Microseconds(0), + base::Microseconds(0), base::Microseconds(0), base::Microseconds(0), + base::Microseconds(0), base::Microseconds(0)}; + expected_latency_predictions.viz_breakdown_stages = { + base::Microseconds(330000), base::Microseconds(23000), + base::Microseconds(170000), base::Microseconds(280000), + base::Microseconds(30000), base::Microseconds(0), + base::Microseconds(0), base::Microseconds(0), + base::Microseconds(0)}; + expected_latency_predictions.total_latency = base::Microseconds(850500); + expected_latency_predictions.total_blink_latency = base::Microseconds(0); + expected_latency_predictions.total_viz_latency = base::Microseconds(833000); + + pipeline_reporter_->CalculateCompositorLatencyPrediction( + actual_latency_predictions, kLatencyPredictionDeviationThreshold); + + VerifyLatencyInfo(expected_latency_predictions, actual_latency_predictions); + + // Third compositor reporter (prediction and actual latency does not differ + // by 8) + pipeline_reporter_ = CreatePipelineReporter(); + pipeline_reporter_->StartStage( + CompositorFrameReporter::StageType::kBeginImplFrameToSendBeginMainFrame, + Now()); + + AdvanceNowByUs(16500); + pipeline_reporter_->StartStage( + CompositorFrameReporter::StageType::kEndActivateToSubmitCompositorFrame, + Now()); + + AdvanceNowByUs(2000); + pipeline_reporter_->StartStage( + CompositorFrameReporter::StageType:: + kSubmitCompositorFrameToPresentationCompositorFrame, + Now()); + + viz_breakdown.received_compositor_frame_timestamp = AdvanceNowByUs(330000); + viz_breakdown.draw_start_timestamp = AdvanceNowByUs(23000); + viz_breakdown.swap_timings.swap_start = AdvanceNowByUs(170000); + viz_breakdown.swap_timings.swap_end = AdvanceNowByUs(280000); + viz_breakdown.presentation_feedback.timestamp = AdvanceNowByUs(30000); + + pipeline_reporter_->SetVizBreakdown(viz_breakdown); + + pipeline_reporter_->TerminateFrame( + CompositorFrameReporter::FrameTerminationStatus::kPresentedFrame, Now()); + + expected_latency_predictions.top_level_stages = { + base::Microseconds(16125), base::Microseconds(0), + base::Microseconds(0), base::Microseconds(0), + base::Microseconds(0), base::Microseconds(1625), + base::Microseconds(833000)}; + expected_latency_predictions.blink_breakdown_stages = { + base::Microseconds(0), base::Microseconds(0), base::Microseconds(0), + base::Microseconds(0), base::Microseconds(0), base::Microseconds(0), + base::Microseconds(0), base::Microseconds(0), base::Microseconds(0), + base::Microseconds(0), base::Microseconds(0)}; + expected_latency_predictions.viz_breakdown_stages = { + base::Microseconds(330000), base::Microseconds(23000), + base::Microseconds(170000), base::Microseconds(280000), + base::Microseconds(30000), base::Microseconds(0), + base::Microseconds(0), base::Microseconds(0), + base::Microseconds(0)}; + expected_latency_predictions.total_latency = base::Microseconds(850750); + expected_latency_predictions.total_blink_latency = base::Microseconds(0); + expected_latency_predictions.total_viz_latency = base::Microseconds(833000); + + pipeline_reporter_->CalculateCompositorLatencyPrediction( + actual_latency_predictions, kLatencyPredictionDeviationThreshold); + + VerifyLatencyInfo(expected_latency_predictions, actual_latency_predictions); + + // Fourth compositor reporter (total duration is 0) + pipeline_reporter_ = CreatePipelineReporter(); + pipeline_reporter_->StartStage( + CompositorFrameReporter::StageType::kBeginImplFrameToSendBeginMainFrame, + Now()); + + AdvanceNowByUs(0); + pipeline_reporter_->StartStage( + CompositorFrameReporter::StageType::kSendBeginMainFrameToCommit, Now()); + + AdvanceNowByUs(0); + pipeline_reporter_->StartStage(CompositorFrameReporter::StageType::kCommit, + Now()); + + AdvanceNowByUs(0); + pipeline_reporter_->StartStage( + CompositorFrameReporter::StageType::kEndCommitToActivation, Now()); + + AdvanceNowByUs(0); + pipeline_reporter_->StartStage( + CompositorFrameReporter::StageType:: + kSubmitCompositorFrameToPresentationCompositorFrame, + Now()); + + AdvanceNowByUs(0); + pipeline_reporter_->TerminateFrame( + CompositorFrameReporter::FrameTerminationStatus::kDidNotProduceFrame, + Now()); + + expected_latency_predictions.top_level_stages = { + base::Microseconds(16125), base::Microseconds(0), + base::Microseconds(0), base::Microseconds(0), + base::Microseconds(0), base::Microseconds(1625), + base::Microseconds(833000)}; + expected_latency_predictions.blink_breakdown_stages = { + base::Microseconds(0), base::Microseconds(0), base::Microseconds(0), + base::Microseconds(0), base::Microseconds(0), base::Microseconds(0), + base::Microseconds(0), base::Microseconds(0), base::Microseconds(0), + base::Microseconds(0), base::Microseconds(0)}; + expected_latency_predictions.viz_breakdown_stages = { + base::Microseconds(330000), base::Microseconds(23000), + base::Microseconds(170000), base::Microseconds(280000), + base::Microseconds(30000), base::Microseconds(0), + base::Microseconds(0), base::Microseconds(0), + base::Microseconds(0)}; + expected_latency_predictions.total_latency = base::Microseconds(850750); + expected_latency_predictions.total_blink_latency = base::Microseconds(0); + expected_latency_predictions.total_viz_latency = base::Microseconds(833000); + + pipeline_reporter_->CalculateCompositorLatencyPrediction( + actual_latency_predictions, kLatencyPredictionDeviationThreshold); + + VerifyLatencyInfo(expected_latency_predictions, actual_latency_predictions); + + // Fifth compositor reporter (prediction and actual latency differ by a lot) + pipeline_reporter_ = CreatePipelineReporter(); + pipeline_reporter_->StartStage( + CompositorFrameReporter::StageType::kBeginImplFrameToSendBeginMainFrame, + Now()); + + AdvanceNowByUs(16000); + pipeline_reporter_->StartStage( + CompositorFrameReporter::StageType::kSendBeginMainFrameToCommit, Now()); + + AdvanceNowByUs(4000); + base::TimeTicks begin_main_frame_start_time = Now(); + + auto blink_breakdown = std::make_unique<BeginMainFrameMetrics>(); + blink_breakdown->handle_input_events = base::Microseconds(12000); + blink_breakdown->animate = base::Microseconds(3000); + blink_breakdown->style_update = base::Microseconds(7000); + blink_breakdown->layout_update = base::Microseconds(19000); + blink_breakdown->accessibility = base::Microseconds(800); + blink_breakdown->prepaint = base::Microseconds(4100); + blink_breakdown->compositing_inputs = base::Microseconds(5100); + blink_breakdown->paint = base::Microseconds(1500); + blink_breakdown->composite_commit = base::Microseconds(1500); + blink_breakdown->update_layers = base::Microseconds(2000); + AdvanceNowByUs(56000); + + pipeline_reporter_->SetBlinkBreakdown(std::move(blink_breakdown), + begin_main_frame_start_time); + + pipeline_reporter_->StartStage(CompositorFrameReporter::StageType::kCommit, + Now()); + + AdvanceNowByUs(6000); + pipeline_reporter_->StartStage( + CompositorFrameReporter::StageType::kEndCommitToActivation, Now()); + + AdvanceNowByUs(3000); + pipeline_reporter_->StartStage( + CompositorFrameReporter::StageType::kActivation, Now()); + + AdvanceNowByUs(300); + pipeline_reporter_->StartStage( + CompositorFrameReporter::StageType::kEndActivateToSubmitCompositorFrame, + Now()); + + AdvanceNowByUs(39000); + pipeline_reporter_->StartStage( + CompositorFrameReporter::StageType:: + kSubmitCompositorFrameToPresentationCompositorFrame, + Now()); + + viz_breakdown.received_compositor_frame_timestamp = AdvanceNowByUs(340000); + viz_breakdown.draw_start_timestamp = AdvanceNowByUs(20000); + viz_breakdown.swap_timings.swap_start = AdvanceNowByUs(160000); + viz_breakdown.swap_timings.swap_end = AdvanceNowByUs(283000); + viz_breakdown.presentation_feedback.timestamp = AdvanceNowByUs(30000); + + pipeline_reporter_->SetVizBreakdown(viz_breakdown); + + pipeline_reporter_->TerminateFrame( + CompositorFrameReporter::FrameTerminationStatus::kPresentedFrame, Now()); + + expected_latency_predictions.top_level_stages = { + base::Microseconds(16093), base::Microseconds(15000), + base::Microseconds(1500), base::Microseconds(750), + base::Microseconds(75), base::Microseconds(10968), + base::Microseconds(833000)}; + expected_latency_predictions.blink_breakdown_stages = { + base::Microseconds(12000), base::Microseconds(3000), + base::Microseconds(7000), base::Microseconds(19000), + base::Microseconds(800), base::Microseconds(4100), + base::Microseconds(5100), base::Microseconds(1500), + base::Microseconds(1500), base::Microseconds(2000), + base::Microseconds(4000)}; + expected_latency_predictions.viz_breakdown_stages = { + base::Microseconds(332500), base::Microseconds(22250), + base::Microseconds(167500), base::Microseconds(280750), + base::Microseconds(30000), base::Microseconds(0), + base::Microseconds(0), base::Microseconds(0), + base::Microseconds(0)}; + expected_latency_predictions.total_latency = base::Microseconds(877387); + expected_latency_predictions.total_blink_latency = base::Microseconds(60000); + expected_latency_predictions.total_viz_latency = base::Microseconds(833000); + + std::vector<std::string> expected_latency_attributions = { + "EndActivateToSubmitCompositorFrame"}; + + pipeline_reporter_->CalculateCompositorLatencyPrediction( + actual_latency_predictions, kLatencyPredictionDeviationThreshold); + std::vector<std::string> actual_latency_attributions = + pipeline_reporter_->high_latency_substages_for_testing(); + + VerifyLatencyInfo(expected_latency_predictions, actual_latency_predictions); + EXPECT_EQ(expected_latency_attributions, actual_latency_attributions); + + pipeline_reporter_ = nullptr; +} + +// Tests that when a frame is presented to the user, event latency predictions +// are reported properly. +TEST_F(CompositorFrameReporterTest, EventLatencyDispatchPredictions) { + std::vector<int> dispatch_times = {300, 300, 300, 300, 300}; + std::unique_ptr<EventMetrics> event_metrics_ptrs[] = { + CreateScrollUpdateEventMetricsWithDispatchTimes( + false, ScrollUpdateEventMetrics::ScrollUpdateType::kContinued, + dispatch_times)}; + 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))}; + + AdvanceNowByUs(300); // Transition time + pipeline_reporter_->StartStage( + CompositorFrameReporter::StageType::kEndActivateToSubmitCompositorFrame, + Now()); + + AdvanceNowByUs(300); // kEndActivateToSubmitCompositorFrame stage duration + pipeline_reporter_->StartStage( + CompositorFrameReporter::StageType:: + kSubmitCompositorFrameToPresentationCompositorFrame, + Now()); + + pipeline_reporter_->AddEventsMetrics(std::move(events_metrics)); + + // Test with no previous stage predictions. + std::vector<base::TimeDelta> expected_predictions1(kNumDispatchStages, + base::Microseconds(-1)); + IntToTimeDeltaVector(expected_predictions1, + std::vector<int>{300, 300, 300, 300, 300}); + base::TimeDelta expected_transition1 = base::Microseconds(300); + base::TimeDelta expected_total1 = base::Microseconds(2100); + CompositorFrameReporter::EventLatencyInfo actual_predictions1 = + CompositorFrameReporter::EventLatencyInfo(kNumDispatchStages, + kNumOfCompositorStages); + pipeline_reporter_->CalculateEventLatencyPrediction( + actual_predictions1, kLatencyPredictionDeviationThreshold); + + // Test with all previous stage predictions. + std::vector<base::TimeDelta> expected_predictions2(kNumDispatchStages, + base::Microseconds(-1)); + IntToTimeDeltaVector(expected_predictions2, + std::vector<int>{262, 300, 412, 225, 450}); + base::TimeDelta expected_transition2 = base::Microseconds(390); + base::TimeDelta expected_total2 = base::Microseconds(2339); + CompositorFrameReporter::EventLatencyInfo actual_predictions2 = + CompositorFrameReporter::EventLatencyInfo(kNumDispatchStages, + kNumOfCompositorStages); + IntToTimeDeltaVector(actual_predictions2.dispatch_durations, + std::vector<int>{250, 300, 450, 200, 500}); + actual_predictions2.transition_duration = base::Microseconds(420); + pipeline_reporter_->CalculateEventLatencyPrediction( + actual_predictions2, kLatencyPredictionDeviationThreshold); + + // Test with some previous stage predictions. + std::vector<base::TimeDelta> expected_predictions3(kNumDispatchStages, + base::Microseconds(-1)); + IntToTimeDeltaVector(expected_predictions3, + std::vector<int>{375, 450, 300, 300, 300}); + base::TimeDelta expected_transition3 = base::Microseconds(270); + base::TimeDelta expected_total3 = base::Microseconds(2295); + CompositorFrameReporter::EventLatencyInfo actual_predictions3 = + CompositorFrameReporter::EventLatencyInfo(kNumDispatchStages, + kNumOfCompositorStages); + IntToTimeDeltaVector(actual_predictions3.dispatch_durations, + std::vector<int>{400, 500, 300, -1, -1}); + actual_predictions3.transition_duration = base::Microseconds(260); + pipeline_reporter_->CalculateEventLatencyPrediction( + actual_predictions3, kLatencyPredictionDeviationThreshold); + + for (int i = 0; i < kNumDispatchStages; i++) { + EXPECT_EQ(expected_predictions1[i], + actual_predictions1.dispatch_durations[i]); + EXPECT_EQ(expected_predictions2[i], + actual_predictions2.dispatch_durations[i]); + EXPECT_EQ(expected_predictions3[i], + actual_predictions3.dispatch_durations[i]); + } + EXPECT_EQ(expected_transition1, actual_predictions1.transition_duration); + EXPECT_EQ(expected_total1, actual_predictions1.total_duration); + EXPECT_EQ(expected_transition2, actual_predictions2.transition_duration); + EXPECT_EQ(expected_total2, actual_predictions2.total_duration); + EXPECT_EQ(expected_transition3, actual_predictions3.transition_duration); + EXPECT_EQ(expected_total3, actual_predictions3.total_duration); + + pipeline_reporter_ = nullptr; +} + +// Tests that when a new frame with missing dispatch stages is presented to +// the user, event latency predictions are reported properly. +TEST_F(CompositorFrameReporterTest, + EventLatencyDispatchPredictionsWithMissingStages) { + // Invalid EventLatency stage durations will cause program to crash, + // validity checked in event_latency_tracing_recorder.cc. + std::vector<int> dispatch_times = {400, 600, 700, -1, -1}; + std::unique_ptr<EventMetrics> event_metrics_ptrs[] = { + CreateScrollUpdateEventMetricsWithDispatchTimes( + false, ScrollUpdateEventMetrics::ScrollUpdateType::kContinued, + dispatch_times)}; + 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))}; + + AdvanceNowByUs(470); // Transition time + pipeline_reporter_->StartStage( + CompositorFrameReporter::StageType::kEndActivateToSubmitCompositorFrame, + Now()); + + AdvanceNowByUs(300); // kEndActivateToSubmitCompositorFrame stage duration + pipeline_reporter_->StartStage( + CompositorFrameReporter::StageType:: + kSubmitCompositorFrameToPresentationCompositorFrame, + Now()); + + pipeline_reporter_->AddEventsMetrics(std::move(events_metrics)); + + // Test with no previous stage predictions. + std::vector<base::TimeDelta> expected_predictions1(kNumDispatchStages, + base::Microseconds(-1)); + IntToTimeDeltaVector(expected_predictions1, + std::vector<int>{400, 600, 700, -1, -1}); + base::TimeDelta expected_transition1 = base::Microseconds(470); + base::TimeDelta expected_total1 = base::Microseconds(2470); + CompositorFrameReporter::EventLatencyInfo actual_predictions1 = + CompositorFrameReporter::EventLatencyInfo(kNumDispatchStages, + kNumOfCompositorStages); + pipeline_reporter_->CalculateEventLatencyPrediction( + actual_predictions1, kLatencyPredictionDeviationThreshold); + + // Test with all previous stage predictions. + std::vector<base::TimeDelta> expected_predictions2(kNumDispatchStages, + base::Microseconds(-1)); + IntToTimeDeltaVector(expected_predictions2, + std::vector<int>{250, 375, 475, 200, 500}); + base::TimeDelta expected_transition2 = base::Microseconds(402); + base::TimeDelta expected_total2 = base::Microseconds(2502); + CompositorFrameReporter::EventLatencyInfo actual_predictions2 = + CompositorFrameReporter::EventLatencyInfo(kNumDispatchStages, + kNumOfCompositorStages); + IntToTimeDeltaVector(actual_predictions2.dispatch_durations, + std::vector<int>{200, 300, 400, 200, 500}); + actual_predictions2.transition_duration = base::Microseconds(380); + pipeline_reporter_->CalculateEventLatencyPrediction( + actual_predictions2, kLatencyPredictionDeviationThreshold); + + // Test with some previous stage predictions. + std::vector<base::TimeDelta> expected_predictions3(kNumDispatchStages, + base::Microseconds(-1)); + IntToTimeDeltaVector(expected_predictions3, + std::vector<int>{400, 525, 745, -1, -1}); + base::TimeDelta expected_transition3 = base::Microseconds(492); + base::TimeDelta expected_total3 = base::Microseconds(2462); + CompositorFrameReporter::EventLatencyInfo actual_predictions3 = + CompositorFrameReporter::EventLatencyInfo(kNumDispatchStages, + kNumOfCompositorStages); + IntToTimeDeltaVector(actual_predictions3.dispatch_durations, + std::vector<int>{400, 500, 760, -1, -1}); + actual_predictions3.transition_duration = base::Microseconds(500); + pipeline_reporter_->CalculateEventLatencyPrediction( + actual_predictions3, kLatencyPredictionDeviationThreshold); + + for (int i = 0; i < kNumDispatchStages; i++) { + EXPECT_EQ(expected_predictions1[i], + actual_predictions1.dispatch_durations[i]); + EXPECT_EQ(expected_predictions2[i], + actual_predictions2.dispatch_durations[i]); + EXPECT_EQ(expected_predictions3[i], + actual_predictions3.dispatch_durations[i]); + } + EXPECT_EQ(expected_transition1, actual_predictions1.transition_duration); + EXPECT_EQ(expected_total1, actual_predictions1.total_duration); + EXPECT_EQ(expected_transition2, actual_predictions2.transition_duration); + EXPECT_EQ(expected_total2, actual_predictions2.total_duration); + EXPECT_EQ(expected_transition3, actual_predictions3.transition_duration); + EXPECT_EQ(expected_total3, actual_predictions3.total_duration); + + pipeline_reporter_ = nullptr; +} + +// Tests that when a frame is presented to the user, event latency predictions +// are reported properly. +TEST_F(CompositorFrameReporterTest, EventLatencyCompositorPredictions) { + std::vector<int> dispatch_times = {300, 300, 300, 300, 300}; + std::unique_ptr<EventMetrics> event_metrics_ptrs[] = { + CreateScrollUpdateEventMetricsWithDispatchTimes( + false, ScrollUpdateEventMetrics::ScrollUpdateType::kContinued, + dispatch_times)}; + 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))}; + + AdvanceNowByUs(300); // Transition time + pipeline_reporter_->StartStage( + CompositorFrameReporter::StageType::kBeginImplFrameToSendBeginMainFrame, + Now()); + + // For this test there are only 3 compositor substages updated which reflects + // a more realistic scenario. + + AdvanceNowByUs(300); // kBeginImplFrameToSendBeginMainFrame duration + pipeline_reporter_->StartStage( + CompositorFrameReporter::StageType::kEndActivateToSubmitCompositorFrame, + Now()); + + AdvanceNowByUs(300); // kEndActivateToSubmitCompositorFrame duration + pipeline_reporter_->StartStage( + CompositorFrameReporter::StageType:: + kSubmitCompositorFrameToPresentationCompositorFrame, + Now()); + + // kSubmitCompositorFrameToPresentationCompositorFrame duration + AdvanceNowByUs(300); + pipeline_reporter_->TerminateFrame( + CompositorFrameReporter::FrameTerminationStatus::kPresentedFrame, Now()); + + pipeline_reporter_->AddEventsMetrics(std::move(events_metrics)); + + // Test with no previous stage predictions. + std::vector<base::TimeDelta> expected_dispatch1(kNumDispatchStages, + base::Microseconds(-1)); + IntToTimeDeltaVector(expected_dispatch1, + std::vector<int>{300, 300, 300, 300, 300}); + base::TimeDelta expected_transition1 = base::Microseconds(300); + std::vector<base::TimeDelta> expected_compositor1(kNumOfCompositorStages, + base::Microseconds(-1)); + IntToTimeDeltaVector(expected_compositor1, + std::vector<int>{300, -1, -1, -1, -1, 300, 300}); + base::TimeDelta expected_total1 = base::Microseconds(2700); + CompositorFrameReporter::EventLatencyInfo actual_predictions1 = + CompositorFrameReporter::EventLatencyInfo(kNumDispatchStages, + kNumOfCompositorStages); + pipeline_reporter_->CalculateEventLatencyPrediction( + actual_predictions1, kLatencyPredictionDeviationThreshold); + + // Test with all previous stage predictions. + std::vector<base::TimeDelta> expected_dispatch2(kNumDispatchStages, + base::Microseconds(-1)); + IntToTimeDeltaVector(expected_dispatch2, + std::vector<int>{262, 300, 412, 225, 450}); + base::TimeDelta expected_transition2 = base::Microseconds(390); + std::vector<base::TimeDelta> expected_compositor2(kNumOfCompositorStages, + base::Microseconds(-1)); + IntToTimeDeltaVector(expected_compositor2, + std::vector<int>{465, 500, 90, 720, 410, 742, 390}); + base::TimeDelta expected_total2 = base::Microseconds(5356); + CompositorFrameReporter::EventLatencyInfo actual_predictions2 = + CompositorFrameReporter::EventLatencyInfo(kNumDispatchStages, + kNumOfCompositorStages); + IntToTimeDeltaVector(actual_predictions2.dispatch_durations, + std::vector<int>{250, 300, 450, 200, 500}); + actual_predictions2.transition_duration = base::Microseconds(420); + IntToTimeDeltaVector(actual_predictions2.compositor_durations, + std::vector<int>{520, 500, 90, 720, 410, 890, 420}); + pipeline_reporter_->CalculateEventLatencyPrediction( + actual_predictions2, kLatencyPredictionDeviationThreshold); + + // Test with some previous stage predictions. + std::vector<base::TimeDelta> expected_dispatch3(kNumDispatchStages, + base::Microseconds(-1)); + IntToTimeDeltaVector(expected_dispatch3, + std::vector<int>{375, 450, 300, 300, 300}); + base::TimeDelta expected_transition3 = base::Microseconds(270); + std::vector<base::TimeDelta> expected_compositor3(kNumOfCompositorStages, + base::Microseconds(-1)); + IntToTimeDeltaVector(expected_compositor3, + std::vector<int>{300, 500, -1, -1, 410, 742, 390}); + base::TimeDelta expected_total3 = base::Microseconds(4337); + CompositorFrameReporter::EventLatencyInfo actual_predictions3 = + CompositorFrameReporter::EventLatencyInfo(kNumDispatchStages, + kNumOfCompositorStages); + IntToTimeDeltaVector(actual_predictions3.dispatch_durations, + std::vector<int>{400, 500, 300, -1, -1}); + actual_predictions3.transition_duration = base::Microseconds(260); + IntToTimeDeltaVector(actual_predictions3.compositor_durations, + std::vector<int>{-1, 500, -1, -1, 410, 890, 420}); + pipeline_reporter_->CalculateEventLatencyPrediction( + actual_predictions3, kLatencyPredictionDeviationThreshold); + + for (int i = 0; i < kNumDispatchStages; i++) { + EXPECT_EQ(expected_dispatch1[i], actual_predictions1.dispatch_durations[i]); + EXPECT_EQ(expected_dispatch2[i], actual_predictions2.dispatch_durations[i]); + EXPECT_EQ(expected_dispatch3[i], actual_predictions3.dispatch_durations[i]); + } + for (int i = 0; i < kNumOfCompositorStages; i++) { + EXPECT_EQ(expected_compositor1[i], + actual_predictions1.compositor_durations[i]); + EXPECT_EQ(expected_compositor2[i], + actual_predictions2.compositor_durations[i]); + EXPECT_EQ(expected_compositor3[i], + actual_predictions3.compositor_durations[i]); + } + EXPECT_EQ(expected_transition1, actual_predictions1.transition_duration); + EXPECT_EQ(expected_total1, actual_predictions1.total_duration); + EXPECT_EQ(expected_transition2, actual_predictions2.transition_duration); + EXPECT_EQ(expected_total2, actual_predictions2.total_duration); + EXPECT_EQ(expected_transition3, actual_predictions3.transition_duration); + EXPECT_EQ(expected_total3, actual_predictions3.total_duration); + + pipeline_reporter_ = nullptr; +} + +// Tests that when a frame is presented to the user, event latency predictions +// are reported properly for filtered EventTypes. +TEST_F(CompositorFrameReporterTest, EventLatencyMultipleEventTypePredictions) { + std::vector<int> dispatch_times = {300, 300, 300, 300, 300}; + // The prediction should only be updated with the ScrollUpdateType event, + // other EventType metrics should be ignored. + std::unique_ptr<EventMetrics> event_metrics_ptrs[] = { + CreateEventMetrics(ui::ET_TOUCH_PRESSED), + CreateEventMetrics(ui::ET_TOUCH_MOVED), + CreateScrollUpdateEventMetricsWithDispatchTimes( + false, ScrollUpdateEventMetrics::ScrollUpdateType::kContinued, + dispatch_times), + CreateEventMetrics(ui::ET_TOUCH_MOVED)}; + // The last ET_TOUCH_MOVED event above adds 12 us to transition time. + const base::TimeDelta kTouchEventTransition = base::Microseconds(12); + 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))}; + + AdvanceNowByUs(300); + // Total transition time is 312 us because of the extra 3 us from the + // ET_TOUCH_MOVED event. + pipeline_reporter_->StartStage( + CompositorFrameReporter::StageType::kBeginImplFrameToSendBeginMainFrame, + Now()); + + // For this test there are only 3 compositor substages updated which reflects + // a more realistic scenario. + + AdvanceNowByUs(300); // kBeginImplFrameToSendBeginMainFrame duration + pipeline_reporter_->StartStage( + CompositorFrameReporter::StageType::kEndActivateToSubmitCompositorFrame, + Now()); + + AdvanceNowByUs(300); // kEndActivateToSubmitCompositorFrame duration + pipeline_reporter_->StartStage( + CompositorFrameReporter::StageType:: + kSubmitCompositorFrameToPresentationCompositorFrame, + Now()); + + // kSubmitCompositorFrameToPresentationCompositorFrame duration + AdvanceNowByUs(300); + pipeline_reporter_->TerminateFrame( + CompositorFrameReporter::FrameTerminationStatus::kPresentedFrame, Now()); + + pipeline_reporter_->AddEventsMetrics(std::move(events_metrics)); + + // Test with no previous stage predictions. + std::vector<base::TimeDelta> expected_dispatch1(kNumDispatchStages, + base::Microseconds(-1)); + IntToTimeDeltaVector(expected_dispatch1, + std::vector<int>{300, 300, 300, 300, 300}); + base::TimeDelta expected_transition1 = + base::Microseconds(300) + kTouchEventTransition; + std::vector<base::TimeDelta> expected_compositor1(kNumOfCompositorStages, + base::Microseconds(-1)); + IntToTimeDeltaVector(expected_compositor1, + std::vector<int>{300, -1, -1, -1, -1, 300, 300}); + base::TimeDelta expected_total1 = + base::Microseconds(2700) + kTouchEventTransition; + CompositorFrameReporter::EventLatencyInfo actual_predictions1 = + CompositorFrameReporter::EventLatencyInfo(kNumDispatchStages, + kNumOfCompositorStages); + pipeline_reporter_->CalculateEventLatencyPrediction( + actual_predictions1, kLatencyPredictionDeviationThreshold); + + // Test with all previous stage predictions. + std::vector<base::TimeDelta> expected_dispatch2(kNumDispatchStages, + base::Microseconds(-1)); + IntToTimeDeltaVector(expected_dispatch2, + std::vector<int>{262, 300, 412, 225, 450}); + base::TimeDelta expected_transition2 = base::Microseconds(393); + std::vector<base::TimeDelta> expected_compositor2(kNumOfCompositorStages, + base::Microseconds(-1)); + IntToTimeDeltaVector(expected_compositor2, + std::vector<int>{465, 500, 90, 720, 410, 742, 390}); + base::TimeDelta expected_total2 = base::Microseconds(5359); + CompositorFrameReporter::EventLatencyInfo actual_predictions2 = + CompositorFrameReporter::EventLatencyInfo(kNumDispatchStages, + kNumOfCompositorStages); + IntToTimeDeltaVector(actual_predictions2.dispatch_durations, + std::vector<int>{250, 300, 450, 200, 500}); + actual_predictions2.transition_duration = base::Microseconds(420); + IntToTimeDeltaVector(actual_predictions2.compositor_durations, + std::vector<int>{520, 500, 90, 720, 410, 890, 420}); + pipeline_reporter_->CalculateEventLatencyPrediction( + actual_predictions2, kLatencyPredictionDeviationThreshold); + + for (int i = 0; i < kNumDispatchStages; i++) { + EXPECT_EQ(expected_dispatch1[i], actual_predictions1.dispatch_durations[i]); + EXPECT_EQ(expected_dispatch2[i], actual_predictions2.dispatch_durations[i]); + } + for (int i = 0; i < kNumOfCompositorStages; i++) { + EXPECT_EQ(expected_compositor1[i], + actual_predictions1.compositor_durations[i]); + EXPECT_EQ(expected_compositor2[i], + actual_predictions2.compositor_durations[i]); + } + EXPECT_EQ(expected_transition1, actual_predictions1.transition_duration); + EXPECT_EQ(expected_total1, actual_predictions1.total_duration); + EXPECT_EQ(expected_transition2, actual_predictions2.transition_duration); + EXPECT_EQ(expected_total2, actual_predictions2.total_duration); + + pipeline_reporter_ = nullptr; +} + +// Tests that when a frame is presented to the user, high latency attribution +// for EventLatency is reported properly for filtered EventTypes. +TEST_F(CompositorFrameReporterTest, EventLatencyAttributionPredictions) { + std::vector<int> dispatch_times = {300, 300, 300, 50000, 300}; + // The prediction should only be updated with the ScrollUpdateType event, + // other EventType metrics should be ignored. + std::unique_ptr<EventMetrics> event_metrics_ptrs[] = { + CreateScrollUpdateEventMetricsWithDispatchTimes( + false, ScrollUpdateEventMetrics::ScrollUpdateType::kContinued, + dispatch_times)}; + 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))}; + + AdvanceNowByUs(300); + pipeline_reporter_->StartStage( + CompositorFrameReporter::StageType::kBeginImplFrameToSendBeginMainFrame, + Now()); + + // For this test there are only 3 compositor substages updated which reflects + // a more realistic scenario. + + AdvanceNowByUs(300); // kBeginImplFrameToSendBeginMainFrame duration + pipeline_reporter_->StartStage( + CompositorFrameReporter::StageType::kEndActivateToSubmitCompositorFrame, + Now()); + + AdvanceNowByUs(50000); // kEndActivateToSubmitCompositorFrame duration + pipeline_reporter_->StartStage( + CompositorFrameReporter::StageType:: + kSubmitCompositorFrameToPresentationCompositorFrame, + Now()); + + // kSubmitCompositorFrameToPresentationCompositorFrame duration + AdvanceNowByUs(300); + pipeline_reporter_->TerminateFrame( + CompositorFrameReporter::FrameTerminationStatus::kPresentedFrame, Now()); + + pipeline_reporter_->AddEventsMetrics(std::move(events_metrics)); + + // Test with no high latency attribution. + CompositorFrameReporter::EventLatencyInfo expected_predictions1 = + CompositorFrameReporter::EventLatencyInfo(kNumDispatchStages, + kNumOfCompositorStages); + IntToTimeDeltaVector(expected_predictions1.dispatch_durations, + std::vector<int>{300, 300, 300, 50000, 300}); + expected_predictions1.transition_duration = base::Microseconds(300); + IntToTimeDeltaVector(expected_predictions1.compositor_durations, + std::vector<int>{300, -1, -1, -1, -1, 50000, 300}); + expected_predictions1.total_duration = base::Microseconds(102100); + + CompositorFrameReporter::EventLatencyInfo actual_predictions1 = + CompositorFrameReporter::EventLatencyInfo(kNumDispatchStages, + kNumOfCompositorStages); + pipeline_reporter_->CalculateEventLatencyPrediction( + actual_predictions1, kLatencyPredictionDeviationThreshold); + + std::unique_ptr<EventMetrics>& event_metrics = + pipeline_reporter_->events_metrics_for_testing()[0]; + std::vector<std::string> attribution = event_metrics->GetHighLatencyStages(); + EXPECT_EQ(0, (int)attribution.size()); + event_metrics->ClearHighLatencyStagesForTesting(); + + // Test with 1 high latency stage attributed. + CompositorFrameReporter::EventLatencyInfo expected_predictions2 = + CompositorFrameReporter::EventLatencyInfo(kNumDispatchStages, + kNumOfCompositorStages); + IntToTimeDeltaVector(expected_predictions2.dispatch_durations, + std::vector<int>{300, 300, 300, 12725, 300}); + expected_predictions2.transition_duration = base::Microseconds(300); + IntToTimeDeltaVector(expected_predictions2.compositor_durations, + std::vector<int>{300, -1, -1, -1, -1, 50000, 300}); + expected_predictions2.total_duration = base::Microseconds(64825); + + CompositorFrameReporter::EventLatencyInfo actual_predictions2 = + CompositorFrameReporter::EventLatencyInfo(kNumDispatchStages, + kNumOfCompositorStages); + IntToTimeDeltaVector(actual_predictions2.dispatch_durations, + std::vector<int>{300, 300, 300, 300, 300}); + actual_predictions2.transition_duration = base::Microseconds(300); + IntToTimeDeltaVector(actual_predictions2.compositor_durations, + std::vector<int>{300, -1, -1, -1, -1, 50000, 300}); + actual_predictions2.total_duration = base::Microseconds(52400); + pipeline_reporter_->CalculateEventLatencyPrediction( + actual_predictions2, kLatencyPredictionDeviationThreshold); + + attribution = event_metrics->GetHighLatencyStages(); + EXPECT_EQ(1, (int)attribution.size()); + EXPECT_EQ("RendererCompositorToMain", attribution[0]); + event_metrics->ClearHighLatencyStagesForTesting(); + + // Test with more than 1 high latency stage attributed. + CompositorFrameReporter::EventLatencyInfo expected_predictions3 = + CompositorFrameReporter::EventLatencyInfo(kNumDispatchStages, + kNumOfCompositorStages); + IntToTimeDeltaVector(expected_predictions3.dispatch_durations, + std::vector<int>{300, 300, 300, 12725, 300}); + expected_predictions3.transition_duration = base::Microseconds(300); + IntToTimeDeltaVector(expected_predictions3.compositor_durations, + std::vector<int>{300, -1, -1, -1, -1, 12725, 300}); + expected_predictions3.total_duration = base::Microseconds(27550); + + CompositorFrameReporter::EventLatencyInfo actual_predictions3 = + CompositorFrameReporter::EventLatencyInfo(kNumDispatchStages, + kNumOfCompositorStages); + IntToTimeDeltaVector(actual_predictions3.dispatch_durations, + std::vector<int>{300, 300, 300, 300, 300}); + actual_predictions3.transition_duration = base::Microseconds(300); + IntToTimeDeltaVector(actual_predictions3.compositor_durations, + std::vector<int>{300, -1, -1, -1, -1, 300, 300}); + actual_predictions3.total_duration = base::Microseconds(2700); + pipeline_reporter_->CalculateEventLatencyPrediction( + actual_predictions3, kLatencyPredictionDeviationThreshold); + + attribution = event_metrics->GetHighLatencyStages(); + EXPECT_EQ(2, (int)attribution.size()); + EXPECT_EQ("RendererCompositorToMain", attribution[0]); + EXPECT_EQ("EndActivateToSubmitCompositorFrame", attribution[1]); + + // Check that all prediction values are accurate. + for (int i = 0; i < kNumDispatchStages; i++) { + EXPECT_EQ(expected_predictions1.dispatch_durations[i], + actual_predictions1.dispatch_durations[i]); + EXPECT_EQ(expected_predictions2.dispatch_durations[i], + actual_predictions2.dispatch_durations[i]); + EXPECT_EQ(expected_predictions3.dispatch_durations[i], + actual_predictions3.dispatch_durations[i]); + } + for (int i = 0; i < kNumOfCompositorStages; i++) { + EXPECT_EQ(expected_predictions1.compositor_durations[i], + actual_predictions1.compositor_durations[i]); + EXPECT_EQ(expected_predictions2.compositor_durations[i], + actual_predictions2.compositor_durations[i]); + EXPECT_EQ(expected_predictions3.compositor_durations[i], + actual_predictions3.compositor_durations[i]); + } + EXPECT_EQ(expected_predictions1.transition_duration, + actual_predictions1.transition_duration); + EXPECT_EQ(expected_predictions1.total_duration, + actual_predictions1.total_duration); + EXPECT_EQ(expected_predictions2.transition_duration, + actual_predictions2.transition_duration); + EXPECT_EQ(expected_predictions2.total_duration, + actual_predictions2.total_duration); + EXPECT_EQ(expected_predictions3.transition_duration, + actual_predictions3.transition_duration); + EXPECT_EQ(expected_predictions3.total_duration, + actual_predictions3.total_duration); + + pipeline_reporter_ = nullptr; +} + +// Tests that when a frame is presented to the user, high latency attribution +// for EventLatency is reported properly for filtered EventTypes. +TEST_F(CompositorFrameReporterTest, EventLatencyAttributionChangePredictions) { + std::vector<int> dispatch_times = {40000, -1, -1, 300, 50000}; + // The prediction should only be updated with the ScrollUpdateType event, + // other EventType metrics should be ignored. + std::unique_ptr<EventMetrics> event_metrics_ptrs[] = { + CreateScrollUpdateEventMetricsWithDispatchTimes( + false, ScrollUpdateEventMetrics::ScrollUpdateType::kContinued, + dispatch_times)}; + 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))}; + + AdvanceNowByUs(300); + pipeline_reporter_->StartStage( + CompositorFrameReporter::StageType::kBeginImplFrameToSendBeginMainFrame, + Now()); + + // For this test there are only 3 compositor substages updated which reflects + // a more realistic scenario. + + AdvanceNowByUs(300); // kBeginImplFrameToSendBeginMainFrame duration + pipeline_reporter_->StartStage( + CompositorFrameReporter::StageType::kEndActivateToSubmitCompositorFrame, + Now()); + + AdvanceNowByUs(50000); // kEndActivateToSubmitCompositorFrame duration + pipeline_reporter_->StartStage( + CompositorFrameReporter::StageType:: + kSubmitCompositorFrameToPresentationCompositorFrame, + Now()); + + // kSubmitCompositorFrameToPresentationCompositorFrame duration + AdvanceNowByUs(300); + pipeline_reporter_->TerminateFrame( + CompositorFrameReporter::FrameTerminationStatus::kPresentedFrame, Now()); + + pipeline_reporter_->AddEventsMetrics(std::move(events_metrics)); + + // Test 1 + CompositorFrameReporter::EventLatencyInfo expected_predictions1 = + CompositorFrameReporter::EventLatencyInfo(kNumDispatchStages, + kNumOfCompositorStages); + IntToTimeDeltaVector(expected_predictions1.dispatch_durations, + std::vector<int>{10300, -1, -1, 300, 42500}); + expected_predictions1.transition_duration = base::Microseconds(300); + IntToTimeDeltaVector(expected_predictions1.compositor_durations, + std::vector<int>{300, -1, -1, -1, -1, 15200, 300}); + expected_predictions1.total_duration = base::Microseconds(69200); + + CompositorFrameReporter::EventLatencyInfo actual_predictions1 = + CompositorFrameReporter::EventLatencyInfo(kNumDispatchStages, + kNumOfCompositorStages); + IntToTimeDeltaVector(actual_predictions1.dispatch_durations, + std::vector<int>{400, -1, -1, 300, 40000}); + actual_predictions1.transition_duration = base::Microseconds(300); + IntToTimeDeltaVector(actual_predictions1.compositor_durations, + std::vector<int>{300, -1, -1, -1, -1, 3600, 300}); + actual_predictions1.total_duration = base::Microseconds(45200); + pipeline_reporter_->CalculateEventLatencyPrediction( + actual_predictions1, kLatencyPredictionDeviationThreshold); + + std::unique_ptr<EventMetrics>& event_metrics = + pipeline_reporter_->events_metrics_for_testing()[0]; + std::vector<std::string> attribution = event_metrics->GetHighLatencyStages(); + EXPECT_EQ(2, (int)attribution.size()); + EXPECT_EQ("GenerationToRendererCompositor", attribution[0]); + EXPECT_EQ("EndActivateToSubmitCompositorFrame", attribution[1]); + event_metrics->ClearHighLatencyStagesForTesting(); + + // Test 2 + CompositorFrameReporter::EventLatencyInfo expected_predictions2 = + CompositorFrameReporter::EventLatencyInfo(kNumDispatchStages, + kNumOfCompositorStages); + IntToTimeDeltaVector(expected_predictions2.dispatch_durations, + std::vector<int>{10225, -1, -1, 300, 12725}); + expected_predictions2.transition_duration = base::Microseconds(300); + + IntToTimeDeltaVector(expected_predictions2.compositor_durations, + std::vector<int>{300, -1, -1, -1, -1, 12725, 300}); + expected_predictions2.total_duration = base::Microseconds(36875); + + CompositorFrameReporter::EventLatencyInfo actual_predictions2 = + CompositorFrameReporter::EventLatencyInfo(kNumDispatchStages, + kNumOfCompositorStages); + IntToTimeDeltaVector(actual_predictions2.dispatch_durations, + std::vector<int>{300, -1, -1, 300, 300}); + actual_predictions2.transition_duration = base::Microseconds(300); + IntToTimeDeltaVector(actual_predictions2.compositor_durations, + std::vector<int>{300, -1, -1, -1, -1, 300, 300}); + actual_predictions2.total_duration = base::Microseconds(2100); + pipeline_reporter_->CalculateEventLatencyPrediction( + actual_predictions2, kLatencyPredictionDeviationThreshold); + + attribution = event_metrics->GetHighLatencyStages(); + EXPECT_EQ(2, (int)attribution.size()); + EXPECT_EQ("RendererMainProcessing", attribution[0]); + EXPECT_EQ("EndActivateToSubmitCompositorFrame", attribution[1]); + + // Check that all prediction values are accurate. + for (int i = 0; i < kNumDispatchStages; i++) { + EXPECT_EQ(expected_predictions1.dispatch_durations[i], + actual_predictions1.dispatch_durations[i]); + EXPECT_EQ(expected_predictions2.dispatch_durations[i], + actual_predictions2.dispatch_durations[i]); + } + for (int i = 0; i < kNumOfCompositorStages; i++) { + EXPECT_EQ(expected_predictions1.compositor_durations[i], + actual_predictions1.compositor_durations[i]); + EXPECT_EQ(expected_predictions2.compositor_durations[i], + actual_predictions2.compositor_durations[i]); + } + EXPECT_EQ(expected_predictions1.transition_duration, + actual_predictions1.transition_duration); + EXPECT_EQ(expected_predictions1.total_duration, + actual_predictions1.total_duration); + EXPECT_EQ(expected_predictions2.transition_duration, + actual_predictions2.transition_duration); + EXPECT_EQ(expected_predictions2.total_duration, + actual_predictions2.total_duration); + + pipeline_reporter_ = nullptr; +} + } // namespace } // namespace cc |