From 98d41f9c50335be545100fb76595cf36913b57fd Mon Sep 17 00:00:00 2001 From: Kaushik Iska Date: Tue, 7 Apr 2020 14:59:36 -0700 Subject: [PATCH] [perf] Add a SceneDisplayLag event when we miss vsyncs This event goes from now -> current vsync target time to avoid the limitations as seen in https://github.com/flutter/flutter/issues/54095#issuecomment-610636237 This event also tags additional metadata to capture `vsync_transitions_missed` considering the refresh rate of the display. --- shell/common/rasterizer.cc | 27 +++++++++++++++++++++++++++ 1 file changed, 27 insertions(+) diff --git a/shell/common/rasterizer.cc b/shell/common/rasterizer.cc index 0a6a060c26382..bce1b2bf036cb 100644 --- a/shell/common/rasterizer.cc +++ b/shell/common/rasterizer.cc @@ -242,6 +242,7 @@ RasterStatus Rasterizer::DoDraw( } FrameTiming timing; + const fml::TimePoint frame_target_time = layer_tree->target_time(); timing.Set(FrameTiming::kBuildStart, layer_tree->build_start()); timing.Set(FrameTiming::kBuildFinish, layer_tree->build_finish()); timing.Set(FrameTiming::kRasterStart, fml::TimePoint::Now()); @@ -271,6 +272,32 @@ RasterStatus Rasterizer::DoDraw( timing.Set(FrameTiming::kRasterFinish, raster_finish_time); delegate_.OnFrameRasterized(timing); + if (raster_finish_time > frame_target_time) { + fml::TimePoint latest_frame_target_time = + delegate_.GetLatestFrameTargetTime(); + const auto frame_budget_millis = delegate_.GetFrameBudget().count(); + if (latest_frame_target_time < raster_finish_time) { + latest_frame_target_time = + latest_frame_target_time + + fml::TimeDelta::FromMillisecondsF(frame_budget_millis); + } + const auto frame_lag = + (latest_frame_target_time - frame_target_time).ToMillisecondsF(); + const int vsync_transitions_missed = round(frame_lag / frame_budget_millis); + fml::tracing::TraceEventAsyncComplete( + "flutter", // category + "SceneDisplayLag", // name + raster_finish_time, // begin_time + latest_frame_target_time, // end_time + "frame_target_time", // arg_key_1 + frame_target_time, // arg_val_1 + "current_frame_target_time", // arg_key_2 + latest_frame_target_time, // arg_val_2 + "vsync_transitions_missed", // arg_key_3 + vsync_transitions_missed // arg_val_3 + ); + } + // Pipeline pressure is applied from a couple of places: // rasterizer: When there are more items as of the time of Consume. // animator (via shell): Frame gets produces every vsync.