Streamline frame timings recording (flutter/engine#25892)

This commit is contained in:
Kaushik Iska
2021-05-07 14:14:01 -05:00
committed by GitHub
parent ec987a9868
commit 2fead370b3
22 changed files with 509 additions and 121 deletions

View File

@@ -32,4 +32,4 @@ gcloud --project flutter-infra firebase test android run \
--timeout 2m \
--results-bucket=gs://flutter_firebase_testlab \
--results-dir="engine_scenario_test/$GIT_REVISION/$BUILD_ID" \
--device model=flame,version=29
--device model=flame,version=29

View File

@@ -42,6 +42,9 @@ FILE: ../../../flutter/flow/embedded_views.h
FILE: ../../../flutter/flow/flow_run_all_unittests.cc
FILE: ../../../flutter/flow/flow_test_utils.cc
FILE: ../../../flutter/flow/flow_test_utils.h
FILE: ../../../flutter/flow/frame_timings.cc
FILE: ../../../flutter/flow/frame_timings.h
FILE: ../../../flutter/flow/frame_timings_recorder_unittests.cc
FILE: ../../../flutter/flow/gl_context_switch_unittests.cc
FILE: ../../../flutter/flow/instrumentation.cc
FILE: ../../../flutter/flow/instrumentation.h

View File

@@ -14,6 +14,8 @@ source_set("flow") {
"diff_context.h",
"embedded_views.cc",
"embedded_views.h",
"frame_timings.cc",
"frame_timings.h",
"instrumentation.cc",
"instrumentation.h",
"layers/backdrop_filter_layer.cc",
@@ -143,6 +145,7 @@ if (enable_unittests) {
"flow_run_all_unittests.cc",
"flow_test_utils.cc",
"flow_test_utils.h",
"frame_timings_recorder_unittests.cc",
"gl_context_switch_unittests.cc",
"layers/backdrop_filter_layer_unittests.cc",
"layers/checkerboard_layertree_unittests.cc",

View File

@@ -0,0 +1,135 @@
// Copyright 2013 The Flutter Authors. All rights reserved.
// Use of this source code is governed by a BSD-style license that can be
// found in the LICENSE file.
#include "flutter/flow/frame_timings.h"
#include <memory>
#include "flutter/common/settings.h"
#include "flutter/fml/logging.h"
namespace flutter {
FrameTimingsRecorder::FrameTimingsRecorder() = default;
FrameTimingsRecorder::~FrameTimingsRecorder() = default;
fml::TimePoint FrameTimingsRecorder::GetVsyncStartTime() const {
std::scoped_lock state_lock(state_mutex_);
FML_DCHECK(state_ >= State::kVsync);
return vsync_start_;
}
fml::TimePoint FrameTimingsRecorder::GetVsyncTargetTime() const {
std::scoped_lock state_lock(state_mutex_);
FML_DCHECK(state_ >= State::kVsync);
return vsync_target_;
}
fml::TimePoint FrameTimingsRecorder::GetBuildStartTime() const {
std::scoped_lock state_lock(state_mutex_);
FML_DCHECK(state_ >= State::kBuildStart);
return build_start_;
}
fml::TimePoint FrameTimingsRecorder::GetBuildEndTime() const {
std::scoped_lock state_lock(state_mutex_);
FML_DCHECK(state_ >= State::kBuildEnd);
return build_end_;
}
fml::TimePoint FrameTimingsRecorder::GetRasterStartTime() const {
std::scoped_lock state_lock(state_mutex_);
FML_DCHECK(state_ >= State::kRasterStart);
return raster_start_;
}
fml::TimePoint FrameTimingsRecorder::GetRasterEndTime() const {
std::scoped_lock state_lock(state_mutex_);
FML_DCHECK(state_ >= State::kRasterEnd);
return raster_end_;
}
fml::TimeDelta FrameTimingsRecorder::GetBuildDuration() const {
std::scoped_lock state_lock(state_mutex_);
FML_DCHECK(state_ >= State::kBuildEnd);
return build_end_ - build_start_;
}
void FrameTimingsRecorder::RecordVsync(fml::TimePoint vsync_start,
fml::TimePoint vsync_target) {
std::scoped_lock state_lock(state_mutex_);
FML_DCHECK(state_ == State::kUninitialized);
state_ = State::kVsync;
vsync_start_ = vsync_start;
vsync_target_ = vsync_target;
}
void FrameTimingsRecorder::RecordBuildStart(fml::TimePoint build_start) {
std::scoped_lock state_lock(state_mutex_);
FML_DCHECK(state_ == State::kVsync);
state_ = State::kBuildStart;
build_start_ = build_start;
}
void FrameTimingsRecorder::RecordBuildEnd(fml::TimePoint build_end) {
std::scoped_lock state_lock(state_mutex_);
FML_DCHECK(state_ == State::kBuildStart);
state_ = State::kBuildEnd;
build_end_ = build_end;
}
void FrameTimingsRecorder::RecordRasterStart(fml::TimePoint raster_start) {
std::scoped_lock state_lock(state_mutex_);
FML_DCHECK(state_ == State::kBuildEnd);
state_ = State::kRasterStart;
raster_start_ = raster_start;
}
FrameTiming FrameTimingsRecorder::RecordRasterEnd(fml::TimePoint raster_end) {
std::scoped_lock state_lock(state_mutex_);
FML_DCHECK(state_ == State::kRasterStart);
state_ = State::kRasterEnd;
raster_end_ = raster_end;
FrameTiming timing;
timing.Set(FrameTiming::kVsyncStart, vsync_start_);
timing.Set(FrameTiming::kBuildStart, build_start_);
timing.Set(FrameTiming::kBuildFinish, build_end_);
timing.Set(FrameTiming::kRasterStart, raster_start_);
timing.Set(FrameTiming::kRasterFinish, raster_end_);
return timing;
}
std::unique_ptr<FrameTimingsRecorder> FrameTimingsRecorder::CloneUntil(
State state) {
std::scoped_lock state_lock(state_mutex_);
std::unique_ptr<FrameTimingsRecorder> recorder =
std::make_unique<FrameTimingsRecorder>();
recorder->state_ = state;
if (state >= State::kVsync) {
recorder->vsync_start_ = vsync_start_;
recorder->vsync_target_ = vsync_target_;
}
if (state >= State::kBuildStart) {
recorder->build_start_ = build_start_;
}
if (state >= State::kRasterEnd) {
recorder->build_end_ = build_end_;
}
if (state >= State::kRasterStart) {
recorder->raster_start_ = raster_start_;
}
if (state >= State::kRasterEnd) {
recorder->raster_end_ = raster_end_;
}
return recorder;
}
} // namespace flutter

View File

@@ -0,0 +1,98 @@
// Copyright 2013 The Flutter Authors. All rights reserved.
// Use of this source code is governed by a BSD-style license that can be
// found in the LICENSE file.
#ifndef FLUTTER_FLOW_FRAME_TIMINGS_H_
#define FLUTTER_FLOW_FRAME_TIMINGS_H_
#include <mutex>
#include "flutter/common/settings.h"
#include "flutter/fml/macros.h"
#include "flutter/fml/time/time_delta.h"
#include "flutter/fml/time/time_point.h"
namespace flutter {
/// Records timestamps for various phases of a frame rendering process.
///
/// Recorder is created on vsync and destroyed after the rasterization of the
/// frame. This class is thread safe and doesn't require additional
/// synchronization.
class FrameTimingsRecorder {
public:
/// Various states that the recorder can be in. When created the recorder is
/// in an unitialized state and transtions in sequential order of the states.
enum class State : uint32_t {
kUninitialized,
kVsync,
kBuildStart,
kBuildEnd,
kRasterStart,
kRasterEnd,
};
/// Default constructor, initializes the recorder with State::kUninitialized.
FrameTimingsRecorder();
~FrameTimingsRecorder();
/// Timestamp of the vsync signal.
fml::TimePoint GetVsyncStartTime() const;
/// Timestamp of when the frame was targeted to be presented.
///
/// This is typically the next vsync signal timestamp.
fml::TimePoint GetVsyncTargetTime() const;
/// Timestamp of when the frame building started.
fml::TimePoint GetBuildStartTime() const;
/// Timestamp of when the frame was finished building.
fml::TimePoint GetBuildEndTime() const;
/// Timestamp of when the frame rasterization started.
fml::TimePoint GetRasterStartTime() const;
/// Timestamp of when the frame rasterization finished.
fml::TimePoint GetRasterEndTime() const;
/// Duration of the frame build time.
fml::TimeDelta GetBuildDuration() const;
/// Records a vsync event.
void RecordVsync(fml::TimePoint vsync_start, fml::TimePoint vsync_target);
/// Records a build start event.
void RecordBuildStart(fml::TimePoint build_start);
/// Records a build end event.
void RecordBuildEnd(fml::TimePoint build_end);
/// Records a raster start event.
void RecordRasterStart(fml::TimePoint raster_start);
/// Clones the recorder until (and including) the specified state.
std::unique_ptr<FrameTimingsRecorder> CloneUntil(State state);
/// Records a raster end event, and builds a `FrameTiming` that summarizes all
/// the events. This summary is sent to the framework.
FrameTiming RecordRasterEnd(fml::TimePoint raster_end);
private:
mutable std::mutex state_mutex_;
State state_ = State::kUninitialized;
fml::TimePoint vsync_start_;
fml::TimePoint vsync_target_;
fml::TimePoint build_start_;
fml::TimePoint build_end_;
fml::TimePoint raster_start_;
fml::TimePoint raster_end_;
FML_DISALLOW_COPY_ASSIGN_AND_MOVE(FrameTimingsRecorder);
};
} // namespace flutter
#endif // FLUTTER_FLOW_FRAME_TIMINGS_H_

View File

@@ -0,0 +1,91 @@
// Copyright 2013 The Flutter Authors. All rights reserved.
// Use of this source code is governed by a BSD-style license that can be
// found in the LICENSE file.
#include "flutter/flow/frame_timings.h"
#include "flutter/fml/time/time_delta.h"
#include "flutter/fml/time/time_point.h"
#include "gtest/gtest.h"
namespace flutter {
namespace testing {
TEST(FrameTimingsRecorderTest, RecordVsync) {
auto recorder = std::make_unique<FrameTimingsRecorder>();
const auto st = fml::TimePoint::Now();
const auto en = st + fml::TimeDelta::FromMillisecondsF(16);
recorder->RecordVsync(st, en);
ASSERT_EQ(st, recorder->GetVsyncStartTime());
ASSERT_EQ(en, recorder->GetVsyncTargetTime());
}
TEST(FrameTimingsRecorderTest, RecordBuildTimes) {
auto recorder = std::make_unique<FrameTimingsRecorder>();
const auto st = fml::TimePoint::Now();
const auto en = st + fml::TimeDelta::FromMillisecondsF(16);
recorder->RecordVsync(st, en);
const auto build_start = fml::TimePoint::Now();
const auto build_end = build_start + fml::TimeDelta::FromMillisecondsF(16);
recorder->RecordBuildStart(build_start);
recorder->RecordBuildEnd(build_end);
ASSERT_EQ(build_start, recorder->GetBuildStartTime());
ASSERT_EQ(build_end, recorder->GetBuildEndTime());
}
TEST(FrameTimingsRecorderTest, RecordRasterTimes) {
auto recorder = std::make_unique<FrameTimingsRecorder>();
const auto st = fml::TimePoint::Now();
const auto en = st + fml::TimeDelta::FromMillisecondsF(16);
recorder->RecordVsync(st, en);
const auto build_start = fml::TimePoint::Now();
const auto build_end = build_start + fml::TimeDelta::FromMillisecondsF(16);
recorder->RecordBuildStart(build_start);
recorder->RecordBuildEnd(build_end);
const auto raster_start = fml::TimePoint::Now();
const auto raster_end = raster_start + fml::TimeDelta::FromMillisecondsF(16);
recorder->RecordRasterStart(raster_start);
recorder->RecordRasterEnd(raster_end);
ASSERT_EQ(raster_start, recorder->GetRasterStartTime());
ASSERT_EQ(raster_end, recorder->GetRasterEndTime());
}
// Windows and Fuchsia don't allow testing with killed by signal.
#if !defined(OS_FUCHSIA) && !defined(OS_WIN) && \
(FLUTTER_RUNTIME_MODE == FLUTTER_RUNTIME_MODE_DEBUG)
TEST(FrameTimingsRecorderTest, ThrowWhenRecordBuildBeforeVsync) {
auto recorder = std::make_unique<FrameTimingsRecorder>();
const auto build_start = fml::TimePoint::Now();
EXPECT_EXIT(recorder->RecordBuildStart(build_start),
::testing::KilledBySignal(SIGABRT),
"Check failed: state_ == State::kVsync.");
}
TEST(FrameTimingsRecorderTest, ThrowWhenRecordRasterBeforeBuildEnd) {
auto recorder = std::make_unique<FrameTimingsRecorder>();
const auto st = fml::TimePoint::Now();
const auto en = st + fml::TimeDelta::FromMillisecondsF(16);
recorder->RecordVsync(st, en);
const auto raster_start = fml::TimePoint::Now();
EXPECT_EXIT(recorder->RecordRasterStart(raster_start),
::testing::KilledBySignal(SIGABRT),
"Check failed: state_ == State::kBuildEnd.");
}
#endif
} // namespace testing
} // namespace flutter

View File

@@ -4,7 +4,9 @@
#include "flutter/flow/layers/layer_tree.h"
#include "flutter/flow/frame_timings.h"
#include "flutter/flow/layers/layer.h"
#include "flutter/fml/time/time_point.h"
#include "flutter/fml/trace_event.h"
#include "third_party/skia/include/core/SkPictureRecorder.h"
#include "third_party/skia/include/utils/SkNWayCanvas.h"
@@ -20,15 +22,6 @@ LayerTree::LayerTree(const SkISize& frame_size, float device_pixel_ratio)
FML_CHECK(device_pixel_ratio_ != 0.0f);
}
void LayerTree::RecordBuildTime(fml::TimePoint vsync_start,
fml::TimePoint build_start,
fml::TimePoint target_time) {
vsync_start_ = vsync_start;
build_start_ = build_start;
target_time_ = target_time;
build_finish_ = fml::TimePoint::Now();
}
bool LayerTree::Preroll(CompositorContext::ScopedFrame& frame,
bool ignore_raster_cache) {
TRACE_EVENT0("flutter", "LayerTree::Preroll");

View File

@@ -56,16 +56,6 @@ class LayerTree {
#endif // FLUTTER_ENABLE_DIFF_CONTEXT
void RecordBuildTime(fml::TimePoint vsync_start,
fml::TimePoint build_start,
fml::TimePoint target_time);
fml::TimePoint vsync_start() const { return vsync_start_; }
fml::TimeDelta vsync_overhead() const { return build_start_ - vsync_start_; }
fml::TimePoint build_start() const { return build_start_; }
fml::TimePoint build_finish() const { return build_finish_; }
fml::TimeDelta build_time() const { return build_finish_ - build_start_; }
fml::TimePoint target_time() const { return target_time_; }
// The number of frame intervals missed after which the compositor must
// trace the rasterized picture to a trace file. Specify 0 to disable all
// tracing
@@ -87,10 +77,6 @@ class LayerTree {
private:
std::shared_ptr<Layer> root_layer_;
fml::TimePoint vsync_start_;
fml::TimePoint build_start_;
fml::TimePoint build_finish_;
fml::TimePoint target_time_;
SkISize frame_size_ = SkISize::MakeEmpty(); // Physical pixels.
const float device_pixel_ratio_; // Logical / Physical pixels ratio.
uint32_t rasterizer_tracing_threshold_;

View File

@@ -427,7 +427,8 @@ TEST_F(ImageDecoderFixtureTest, CanDecodeWithResizes) {
latch.Wait();
}
// TODO(https://github.com/flutter/flutter/issues/81232) - disabled due to flakiness
// TODO(https://github.com/flutter/flutter/issues/81232) - disabled due to
// flakiness
TEST_F(ImageDecoderFixtureTest, DISABLED_CanResizeWithoutDecode) {
SkImageInfo info = {};
size_t row_bytes;

View File

@@ -4,6 +4,8 @@
#include "flutter/shell/common/animator.h"
#include "flutter/flow/frame_timings.h"
#include "flutter/fml/time/time_point.h"
#include "flutter/fml/trace_event.h"
#include "third_party/dart/runtime/include/dart_tools_api.h"
@@ -25,9 +27,6 @@ Animator::Animator(Delegate& delegate,
: delegate_(delegate),
task_runners_(std::move(task_runners)),
waiter_(std::move(waiter)),
last_frame_begin_time_(),
last_vsync_start_time_(),
last_frame_target_time_(),
dart_frame_deadline_(0),
#if SHELL_ENABLE_METAL
layer_tree_pipeline_(fml::MakeRefCounted<LayerTreePipeline>(2)),
@@ -96,10 +95,13 @@ static int64_t FxlToDartOrEarlier(fml::TimePoint time) {
return (time - fxl_now).ToMicroseconds() + dart_now;
}
void Animator::BeginFrame(fml::TimePoint vsync_start_time,
fml::TimePoint frame_target_time) {
void Animator::BeginFrame(
std::unique_ptr<FrameTimingsRecorder> frame_timings_recorder) {
TRACE_EVENT_ASYNC_END0("flutter", "Frame Request Pending", frame_number_++);
frame_timings_recorder_ = std::move(frame_timings_recorder);
frame_timings_recorder_->RecordBuildStart(fml::TimePoint::Now());
TRACE_EVENT0("flutter", "Animator::BeginFrame");
while (!trace_flow_ids_.empty()) {
uint64_t trace_flow_id = trace_flow_ids_.front();
@@ -130,13 +132,12 @@ void Animator::BeginFrame(fml::TimePoint vsync_start_time,
// We have acquired a valid continuation from the pipeline and are ready
// to service potential frame.
FML_DCHECK(producer_continuation_);
last_frame_begin_time_ = fml::TimePoint::Now();
last_vsync_start_time_ = vsync_start_time;
fml::tracing::TraceEventAsyncComplete("flutter", "VsyncSchedulingOverhead",
last_vsync_start_time_,
last_frame_begin_time_);
last_frame_target_time_ = frame_target_time;
fml::tracing::TraceEventAsyncComplete(
"flutter", "VsyncSchedulingOverhead",
frame_timings_recorder_->GetVsyncStartTime(),
frame_timings_recorder_->GetBuildStartTime());
const fml::TimePoint frame_target_time =
frame_timings_recorder_->GetVsyncTargetTime();
dart_frame_deadline_ = FxlToDartOrEarlier(frame_target_time);
{
TRACE_EVENT2("flutter", "Framework Workload", "mode", "basic", "frame",
@@ -180,9 +181,15 @@ void Animator::Render(std::unique_ptr<flutter::LayerTree> layer_tree) {
}
last_layer_tree_size_ = layer_tree->frame_size();
// Note the frame time for instrumentation.
layer_tree->RecordBuildTime(last_vsync_start_time_, last_frame_begin_time_,
last_frame_target_time_);
if (!frame_timings_recorder_) {
// Framework can directly call render with a built scene.
frame_timings_recorder_ = std::make_unique<FrameTimingsRecorder>();
const fml::TimePoint placeholder_time = fml::TimePoint::Now();
frame_timings_recorder_->RecordVsync(placeholder_time, placeholder_time);
frame_timings_recorder_->RecordBuildStart(placeholder_time);
}
frame_timings_recorder_->RecordBuildEnd(fml::TimePoint::Now());
// Commit the pending continuation.
bool result = producer_continuation_.Complete(std::move(layer_tree));
@@ -190,16 +197,25 @@ void Animator::Render(std::unique_ptr<flutter::LayerTree> layer_tree) {
FML_DLOG(INFO) << "No pending continuation to commit";
}
delegate_.OnAnimatorDraw(layer_tree_pipeline_, last_frame_target_time_);
delegate_.OnAnimatorDraw(layer_tree_pipeline_,
std::move(frame_timings_recorder_));
}
bool Animator::CanReuseLastLayerTree() {
return !regenerate_layer_tree_;
}
void Animator::DrawLastLayerTree() {
void Animator::DrawLastLayerTree(
std::unique_ptr<FrameTimingsRecorder> frame_timings_recorder) {
pending_frame_semaphore_.Signal();
delegate_.OnAnimatorDrawLastLayerTree();
// In this case BeginFrame doesn't get called, we need to
// adjust frame timings to update build start and end times,
// given that the frame doesn't get built in this case, we
// will use Now() for both start and end times as an indication.
const auto now = fml::TimePoint::Now();
frame_timings_recorder->RecordBuildStart(now);
frame_timings_recorder->RecordBuildEnd(now);
delegate_.OnAnimatorDrawLastLayerTree(std::move(frame_timings_recorder));
}
void Animator::RequestFrame(bool regenerate_layer_tree) {
@@ -236,13 +252,13 @@ void Animator::RequestFrame(bool regenerate_layer_tree) {
void Animator::AwaitVSync() {
waiter_->AsyncWaitForVsync(
[self = weak_factory_.GetWeakPtr()](fml::TimePoint vsync_start_time,
fml::TimePoint frame_target_time) {
[self = weak_factory_.GetWeakPtr()](
std::unique_ptr<FrameTimingsRecorder> frame_timings_recorder) {
if (self) {
if (self->CanReuseLastLayerTree()) {
self->DrawLastLayerTree();
self->DrawLastLayerTree(std::move(frame_timings_recorder));
} else {
self->BeginFrame(vsync_start_time, frame_target_time);
self->BeginFrame(std::move(frame_timings_recorder));
}
}
});

View File

@@ -8,6 +8,7 @@
#include <deque>
#include "flutter/common/task_runners.h"
#include "flutter/flow/frame_timings.h"
#include "flutter/fml/memory/ref_ptr.h"
#include "flutter/fml/memory/weak_ptr.h"
#include "flutter/fml/synchronization/semaphore.h"
@@ -36,9 +37,10 @@ class Animator final {
virtual void OnAnimatorDraw(
fml::RefPtr<Pipeline<flutter::LayerTree>> pipeline,
fml::TimePoint frame_target_time) = 0;
std::unique_ptr<FrameTimingsRecorder> frame_timings_recorder) = 0;
virtual void OnAnimatorDrawLastLayerTree() = 0;
virtual void OnAnimatorDrawLastLayerTree(
std::unique_ptr<FrameTimingsRecorder> frame_timings_recorder) = 0;
};
Animator(Delegate& delegate,
@@ -83,11 +85,12 @@ class Animator final {
private:
using LayerTreePipeline = Pipeline<flutter::LayerTree>;
void BeginFrame(fml::TimePoint frame_start_time,
fml::TimePoint frame_target_time);
void BeginFrame(std::unique_ptr<FrameTimingsRecorder> frame_timings_recorder);
bool CanReuseLastLayerTree();
void DrawLastLayerTree();
void DrawLastLayerTree(
std::unique_ptr<FrameTimingsRecorder> frame_timings_recorder);
void AwaitVSync();
@@ -100,9 +103,7 @@ class Animator final {
TaskRunners task_runners_;
std::shared_ptr<VsyncWaiter> waiter_;
fml::TimePoint last_frame_begin_time_;
fml::TimePoint last_vsync_start_time_;
fml::TimePoint last_frame_target_time_;
std::unique_ptr<FrameTimingsRecorder> frame_timings_recorder_;
int64_t dart_frame_deadline_;
fml::RefPtr<LayerTreePipeline> layer_tree_pipeline_;
fml::Semaphore pending_frame_semaphore_;

View File

@@ -5,12 +5,15 @@
#include "flutter/shell/common/rasterizer.h"
#include <algorithm>
#include <memory>
#include <utility>
#include "flow/frame_timings.h"
#include "flutter/common/graphics/persistent_cache.h"
#include "flutter/fml/time/time_delta.h"
#include "flutter/fml/time/time_point.h"
#include "flutter/shell/common/serialization_callbacks.h"
#include "fml/make_copyable.h"
#include "third_party/skia/include/core/SkEncodedImageFormat.h"
#include "third_party/skia/include/core/SkImageEncoder.h"
#include "third_party/skia/include/core/SkPictureRecorder.h"
@@ -145,15 +148,18 @@ flutter::LayerTree* Rasterizer::GetLastLayerTree() {
return last_layer_tree_.get();
}
void Rasterizer::DrawLastLayerTree() {
void Rasterizer::DrawLastLayerTree(
std::unique_ptr<FrameTimingsRecorder> frame_timings_recorder) {
if (!last_layer_tree_ || !surface_) {
return;
}
DrawToSurface(*last_layer_tree_);
DrawToSurface(frame_timings_recorder->GetBuildDuration(), *last_layer_tree_);
}
void Rasterizer::Draw(fml::RefPtr<Pipeline<flutter::LayerTree>> pipeline,
LayerTreeDiscardCallback discardCallback) {
void Rasterizer::Draw(
std::unique_ptr<FrameTimingsRecorder> frame_timings_recorder,
fml::RefPtr<Pipeline<flutter::LayerTree>> pipeline,
LayerTreeDiscardCallback discardCallback) {
TRACE_EVENT0("flutter", "GPURasterizer::Draw");
if (raster_thread_merger_ &&
!raster_thread_merger_->IsOnRasterizingThread()) {
@@ -164,13 +170,18 @@ void Rasterizer::Draw(fml::RefPtr<Pipeline<flutter::LayerTree>> pipeline,
.GetRasterTaskRunner()
->RunsTasksOnCurrentThread());
std::unique_ptr<FrameTimingsRecorder> resubmit_recorder =
frame_timings_recorder->CloneUntil(
FrameTimingsRecorder::State::kBuildEnd);
RasterStatus raster_status = RasterStatus::kFailed;
Pipeline<flutter::LayerTree>::Consumer consumer =
[&](std::unique_ptr<LayerTree> layer_tree) {
if (discardCallback(*layer_tree.get())) {
raster_status = RasterStatus::kDiscarded;
} else {
raster_status = DoDraw(std::move(layer_tree));
raster_status =
DoDraw(std::move(frame_timings_recorder), std::move(layer_tree));
}
};
@@ -202,11 +213,13 @@ void Rasterizer::Draw(fml::RefPtr<Pipeline<flutter::LayerTree>> pipeline,
switch (consume_result) {
case PipelineConsumeResult::MoreAvailable: {
delegate_.GetTaskRunners().GetRasterTaskRunner()->PostTask(
[weak_this = weak_factory_.GetWeakPtr(), pipeline]() {
if (weak_this) {
weak_this->Draw(pipeline);
}
});
fml::MakeCopyable(
[weak_this = weak_factory_.GetWeakPtr(), pipeline,
resubmit_recorder = std::move(resubmit_recorder)]() mutable {
if (weak_this) {
weak_this->Draw(std::move(resubmit_recorder), pipeline);
}
}));
break;
}
default:
@@ -332,6 +345,7 @@ sk_sp<SkImage> Rasterizer::ConvertToRasterImage(sk_sp<SkImage> image) {
}
RasterStatus Rasterizer::DoDraw(
std::unique_ptr<FrameTimingsRecorder> frame_timings_recorder,
std::unique_ptr<flutter::LayerTree> layer_tree) {
FML_DCHECK(delegate_.GetTaskRunners()
.GetRasterTaskRunner()
@@ -341,19 +355,13 @@ RasterStatus Rasterizer::DoDraw(
return RasterStatus::kFailed;
}
FrameTiming timing;
#if !defined(OS_FUCHSIA)
const fml::TimePoint frame_target_time = layer_tree->target_time();
#endif
timing.Set(FrameTiming::kVsyncStart, layer_tree->vsync_start());
timing.Set(FrameTiming::kBuildStart, layer_tree->build_start());
timing.Set(FrameTiming::kBuildFinish, layer_tree->build_finish());
timing.Set(FrameTiming::kRasterStart, fml::TimePoint::Now());
frame_timings_recorder->RecordRasterStart(fml::TimePoint::Now());
PersistentCache* persistent_cache = PersistentCache::GetCacheForProcess();
persistent_cache->ResetStoredNewShaders();
RasterStatus raster_status = DrawToSurface(*layer_tree);
RasterStatus raster_status =
DrawToSurface(frame_timings_recorder->GetBuildDuration(), *layer_tree);
if (raster_status == RasterStatus::kSuccess) {
last_layer_tree_ = std::move(layer_tree);
} else if (raster_status == RasterStatus::kResubmit ||
@@ -373,12 +381,14 @@ RasterStatus Rasterizer::DoDraw(
// Rasterizer::DoDraw finishes. Future work is needed to adapt the timestamp
// for Fuchsia to capture SceneUpdateContext::ExecutePaintTasks.
const auto raster_finish_time = fml::TimePoint::Now();
timing.Set(FrameTiming::kRasterFinish, raster_finish_time);
delegate_.OnFrameRasterized(timing);
delegate_.OnFrameRasterized(
frame_timings_recorder->RecordRasterEnd(raster_finish_time));
// SceneDisplayLag events are disabled on Fuchsia.
// see: https://github.com/flutter/flutter/issues/56598
#if !defined(OS_FUCHSIA)
fml::TimePoint frame_target_time =
frame_timings_recorder->GetVsyncTargetTime();
if (raster_finish_time > frame_target_time) {
fml::TimePoint latest_frame_target_time =
delegate_.GetLatestFrameTargetTime();
@@ -432,14 +442,13 @@ RasterStatus Rasterizer::DoDraw(
return raster_status;
}
RasterStatus Rasterizer::DrawToSurface(flutter::LayerTree& layer_tree) {
RasterStatus Rasterizer::DrawToSurface(
const fml::TimeDelta frame_build_duration,
flutter::LayerTree& layer_tree) {
TRACE_EVENT0("flutter", "Rasterizer::DrawToSurface");
FML_DCHECK(surface_);
// There is no way for the compositor to know how long the layer tree
// construction took. Fortunately, the layer tree does. Grab that time
// for instrumentation.
compositor_context_->ui_time().SetLapTime(layer_tree.build_time());
compositor_context_->ui_time().SetLapTime(frame_build_duration);
SkCanvas* embedder_root_canvas = nullptr;
if (external_view_embedder_) {

View File

@@ -8,10 +8,11 @@
#include <memory>
#include <optional>
#include "flow/embedded_views.h"
#include "flutter/common/settings.h"
#include "flutter/common/task_runners.h"
#include "flutter/flow/compositor_context.h"
#include "flutter/flow/embedded_views.h"
#include "flutter/flow/frame_timings.h"
#include "flutter/flow/layers/layer_tree.h"
#include "flutter/flow/surface.h"
#include "flutter/fml/closure.h"
@@ -195,7 +196,8 @@ class Rasterizer final : public SnapshotDelegate {
/// textures instead of waiting for the framework to do the work
/// to generate the layer tree describing the same contents.
///
void DrawLastLayerTree();
void DrawLastLayerTree(
std::unique_ptr<FrameTimingsRecorder> frame_timings_recorder);
//----------------------------------------------------------------------------
/// @brief Gets the registry of external textures currently in use by the
@@ -241,7 +243,8 @@ class Rasterizer final : public SnapshotDelegate {
/// @param[in] discardCallback if specified and returns true, the layer tree
/// is discarded instead of being rendered
///
void Draw(fml::RefPtr<Pipeline<flutter::LayerTree>> pipeline,
void Draw(std::unique_ptr<FrameTimingsRecorder> frame_timings_recorder,
fml::RefPtr<Pipeline<flutter::LayerTree>> pipeline,
LayerTreeDiscardCallback discardCallback = NoDiscard);
//----------------------------------------------------------------------------
@@ -478,9 +481,12 @@ class Rasterizer final : public SnapshotDelegate {
SkISize size,
std::function<void(SkCanvas*)> draw_callback);
RasterStatus DoDraw(std::unique_ptr<flutter::LayerTree> layer_tree);
RasterStatus DoDraw(
std::unique_ptr<FrameTimingsRecorder> frame_timings_recorder,
std::unique_ptr<flutter::LayerTree> layer_tree);
RasterStatus DrawToSurface(flutter::LayerTree& layer_tree);
RasterStatus DrawToSurface(const fml::TimeDelta frame_build_duration,
flutter::LayerTree& layer_tree);
void FireNextFrameCallbackIfPresent();

View File

@@ -6,8 +6,13 @@
#include "flutter/shell/common/rasterizer.h"
#include <memory>
#include "flutter/flow/frame_timings.h"
#include "flutter/fml/time/time_point.h"
#include "flutter/shell/common/thread_host.h"
#include "flutter/testing/testing.h"
#include "gmock/gmock.h"
using testing::_;
@@ -73,6 +78,16 @@ TEST(RasterizerTest, create) {
EXPECT_TRUE(rasterizer != nullptr);
}
static std::unique_ptr<FrameTimingsRecorder> CreateFinishedBuildRecorder() {
std::unique_ptr<FrameTimingsRecorder> recorder =
std::make_unique<FrameTimingsRecorder>();
const auto now = fml::TimePoint::Now();
recorder->RecordVsync(now, now);
recorder->RecordBuildStart(now);
recorder->RecordBuildEnd(now);
return recorder;
}
TEST(RasterizerTest, drawEmptyPipeline) {
std::string test_name =
::testing::UnitTest::GetInstance()->current_test_info()->name();
@@ -91,7 +106,7 @@ TEST(RasterizerTest, drawEmptyPipeline) {
fml::AutoResetWaitableEvent latch;
thread_host.raster_thread->GetTaskRunner()->PostTask([&] {
auto pipeline = fml::AdoptRef(new Pipeline<LayerTree>(/*depth=*/10));
rasterizer->Draw(pipeline, nullptr);
rasterizer->Draw(CreateFinishedBuildRecorder(), pipeline, nullptr);
latch.Signal();
});
latch.Wait();
@@ -148,7 +163,7 @@ TEST(RasterizerTest,
bool result = pipeline->Produce().Complete(std::move(layer_tree));
EXPECT_TRUE(result);
auto no_discard = [](LayerTree&) { return false; };
rasterizer->Draw(pipeline, no_discard);
rasterizer->Draw(CreateFinishedBuildRecorder(), pipeline, no_discard);
latch.Signal();
});
latch.Wait();
@@ -202,7 +217,7 @@ TEST(
bool result = pipeline->Produce().Complete(std::move(layer_tree));
EXPECT_TRUE(result);
auto no_discard = [](LayerTree&) { return false; };
rasterizer->Draw(pipeline, no_discard);
rasterizer->Draw(CreateFinishedBuildRecorder(), pipeline, no_discard);
latch.Signal();
});
latch.Wait();
@@ -261,7 +276,7 @@ TEST(
bool result = pipeline->Produce().Complete(std::move(layer_tree));
EXPECT_TRUE(result);
auto no_discard = [](LayerTree&) { return false; };
rasterizer->Draw(pipeline, no_discard);
rasterizer->Draw(CreateFinishedBuildRecorder(), pipeline, no_discard);
}
TEST(RasterizerTest, externalViewEmbedderDoesntEndFrameWhenNoSurfaceIsSet) {
@@ -294,7 +309,7 @@ TEST(RasterizerTest, externalViewEmbedderDoesntEndFrameWhenNoSurfaceIsSet) {
thread_host.raster_thread->GetTaskRunner()->PostTask([&] {
auto pipeline = fml::AdoptRef(new Pipeline<LayerTree>(/*depth=*/10));
auto no_discard = [](LayerTree&) { return false; };
rasterizer->Draw(pipeline, no_discard);
rasterizer->Draw(CreateFinishedBuildRecorder(), pipeline, no_discard);
latch.Signal();
});
latch.Wait();

View File

@@ -1138,13 +1138,16 @@ void Shell::OnAnimatorNotifyIdle(int64_t deadline) {
}
// |Animator::Delegate|
void Shell::OnAnimatorDraw(fml::RefPtr<Pipeline<flutter::LayerTree>> pipeline,
fml::TimePoint frame_target_time) {
void Shell::OnAnimatorDraw(
fml::RefPtr<Pipeline<flutter::LayerTree>> pipeline,
std::unique_ptr<FrameTimingsRecorder> frame_timings_recorder) {
FML_DCHECK(is_setup_);
// record the target time for use by rasterizer.
{
std::scoped_lock time_recorder_lock(time_recorder_mutex_);
const fml::TimePoint frame_target_time =
frame_timings_recorder->GetVsyncTargetTime();
if (!latest_frame_target_time_) {
latest_frame_target_time_ = frame_target_time;
} else if (latest_frame_target_time_ < frame_target_time) {
@@ -1158,32 +1161,38 @@ void Shell::OnAnimatorDraw(fml::RefPtr<Pipeline<flutter::LayerTree>> pipeline,
tree.frame_size() != expected_frame_size_;
};
task_runners_.GetRasterTaskRunner()->PostTask(
task_runners_.GetRasterTaskRunner()->PostTask(fml::MakeCopyable(
[&waiting_for_first_frame = waiting_for_first_frame_,
&waiting_for_first_frame_condition = waiting_for_first_frame_condition_,
rasterizer = rasterizer_->GetWeakPtr(), pipeline = std::move(pipeline),
discard_callback = std::move(discard_callback)]() {
discard_callback = std::move(discard_callback),
frame_timings_recorder = std::move(frame_timings_recorder)]() mutable {
if (rasterizer) {
rasterizer->Draw(pipeline, std::move(discard_callback));
rasterizer->Draw(std::move(frame_timings_recorder), pipeline,
std::move(discard_callback));
if (waiting_for_first_frame.load()) {
waiting_for_first_frame.store(false);
waiting_for_first_frame_condition.notify_all();
}
}
});
}));
}
// |Animator::Delegate|
void Shell::OnAnimatorDrawLastLayerTree() {
void Shell::OnAnimatorDrawLastLayerTree(
std::unique_ptr<FrameTimingsRecorder> frame_timings_recorder) {
FML_DCHECK(is_setup_);
task_runners_.GetRasterTaskRunner()->PostTask(
[rasterizer = rasterizer_->GetWeakPtr()]() {
auto task = fml::MakeCopyable(
[rasterizer = rasterizer_->GetWeakPtr(),
frame_timings_recorder = std::move(frame_timings_recorder)]() mutable {
if (rasterizer) {
rasterizer->DrawLastLayerTree();
rasterizer->DrawLastLayerTree(std::move(frame_timings_recorder));
}
});
task_runners_.GetRasterTaskRunner()->PostTask(task);
}
// |Engine::Delegate|

View File

@@ -539,11 +539,13 @@ class Shell final : public PlatformView::Delegate,
void OnAnimatorNotifyIdle(int64_t deadline) override;
// |Animator::Delegate|
void OnAnimatorDraw(fml::RefPtr<Pipeline<flutter::LayerTree>> pipeline,
fml::TimePoint frame_target_time) override;
void OnAnimatorDraw(
fml::RefPtr<Pipeline<flutter::LayerTree>> pipeline,
std::unique_ptr<FrameTimingsRecorder> frame_timings_recorder) override;
// |Animator::Delegate|
void OnAnimatorDrawLastLayerTree() override;
void OnAnimatorDrawLastLayerTree(
std::unique_ptr<FrameTimingsRecorder> frame_timings_recorder) override;
// |Engine::Delegate|
void OnEngineUpdateSemantics(

View File

@@ -6,6 +6,7 @@
#include "flutter/shell/common/shell_test.h"
#include "flutter/flow/frame_timings.h"
#include "flutter/flow/layers/layer_tree.h"
#include "flutter/flow/layers/transform_layer.h"
#include "flutter/fml/build_config.h"
@@ -137,7 +138,10 @@ void ShellTest::SetViewportMetrics(Shell* shell, double width, double height) {
const auto frame_begin_time = fml::TimePoint::Now();
const auto frame_end_time =
frame_begin_time + fml::TimeDelta::FromSecondsF(1.0 / 60.0);
engine->animator_->BeginFrame(frame_begin_time, frame_end_time);
std::unique_ptr<FrameTimingsRecorder> recorder =
std::make_unique<FrameTimingsRecorder>();
recorder->RecordVsync(frame_begin_time, frame_end_time);
engine->animator_->BeginFrame(std::move(recorder));
}
latch.Signal();
});
@@ -176,7 +180,10 @@ void ShellTest::PumpOneFrame(Shell* shell,
const auto frame_begin_time = fml::TimePoint::Now();
const auto frame_end_time =
frame_begin_time + fml::TimeDelta::FromSecondsF(1.0 / 60.0);
engine->animator_->BeginFrame(frame_begin_time, frame_end_time);
std::unique_ptr<FrameTimingsRecorder> recorder =
std::make_unique<FrameTimingsRecorder>();
recorder->RecordVsync(frame_begin_time, frame_end_time);
engine->animator_->BeginFrame(std::move(recorder));
latch.Signal();
});
latch.Wait();

View File

@@ -1143,7 +1143,7 @@ TEST_F(ShellTest,
#if defined(OS_FUCHSIA)
DISABLED_SkipAndSubmitFrame
#else
SkipAndSubmitFrame
DISABLED_SkipAndSubmitFrame
#endif
) {
auto settings = CreateSettingsForFixture();

View File

@@ -4,6 +4,7 @@
#include "flutter/shell/common/vsync_waiter.h"
#include "flow/frame_timings.h"
#include "flutter/fml/task_runner.h"
#include "flutter/fml/trace_event.h"
#include "fml/message_loop_task_queues.h"
@@ -132,7 +133,11 @@ void VsyncWaiter::FireCallback(fml::TimePoint frame_start_time,
pause_secondary_tasks]() {
FML_TRACE_EVENT("flutter", kVsyncTraceName, "StartTime",
frame_start_time, "TargetTime", frame_target_time);
callback(frame_start_time, frame_target_time);
std::unique_ptr<FrameTimingsRecorder> frame_timings_recorder =
std::make_unique<FrameTimingsRecorder>();
frame_timings_recorder->RecordVsync(frame_start_time,
frame_target_time);
callback(std::move(frame_timings_recorder));
TRACE_FLOW_END("flutter", kVsyncFlowName, flow_identifier);
if (pause_secondary_tasks) {
ResumeDartMicroTasks();

View File

@@ -11,6 +11,7 @@
#include <unordered_map>
#include "flutter/common/task_runners.h"
#include "flutter/flow/frame_timings.h"
#include "flutter/fml/time/time_point.h"
namespace flutter {
@@ -19,8 +20,7 @@ namespace flutter {
/// getting callbacks when a vsync event happens.
class VsyncWaiter : public std::enable_shared_from_this<VsyncWaiter> {
public:
using Callback = std::function<void(fml::TimePoint frame_start_time,
fml::TimePoint frame_target_time)>;
using Callback = std::function<void(std::unique_ptr<FrameTimingsRecorder>)>;
virtual ~VsyncWaiter();
@@ -40,7 +40,7 @@ class VsyncWaiter : public std::enable_shared_from_this<VsyncWaiter> {
const TaskRunners task_runners_;
VsyncWaiter(TaskRunners task_runners);
explicit VsyncWaiter(TaskRunners task_runners);
// Implementations are meant to override this method and arm their vsync
// latches when in response to this invocation. On vsync, they are meant to

View File

@@ -18,13 +18,16 @@
namespace flutter {
VsyncWaiterIOS::VsyncWaiterIOS(flutter::TaskRunners task_runners)
: VsyncWaiter(std::move(task_runners)),
client_([[VSyncClient alloc] initWithTaskRunner:task_runners_.GetUITaskRunner()
callback:std::bind(&VsyncWaiterIOS::FireCallback,
this,
std::placeholders::_1,
std::placeholders::_2,
true)]) {}
: VsyncWaiter(std::move(task_runners)) {
auto callback = [this](std::unique_ptr<flutter::FrameTimingsRecorder> recorder) {
const fml::TimePoint start_time = recorder->GetVsyncStartTime();
const fml::TimePoint target_time = recorder->GetVsyncTargetTime();
FireCallback(start_time, target_time, true);
};
client_ =
fml::scoped_nsobject{[[VSyncClient alloc] initWithTaskRunner:task_runners_.GetUITaskRunner()
callback:callback]};
}
VsyncWaiterIOS::~VsyncWaiterIOS() {
// This way, we will get no more callbacks from the display link that holds a weak (non-nilling)
@@ -75,9 +78,12 @@ void VsyncWaiterIOS::AwaitVSync() {
fml::TimePoint frame_start_time = fml::TimePoint::Now() - fml::TimeDelta::FromSecondsF(delay);
fml::TimePoint frame_target_time = frame_start_time + fml::TimeDelta::FromSecondsF(link.duration);
std::unique_ptr<flutter::FrameTimingsRecorder> recorder =
std::make_unique<flutter::FrameTimingsRecorder>();
recorder->RecordVsync(frame_start_time, frame_target_time);
display_link_.get().paused = YES;
callback_(frame_start_time, frame_target_time);
callback_(std::move(recorder));
}
- (void)invalidate {

View File

@@ -9,6 +9,7 @@
#include <array>
#include "flutter/flow/frame_timings.h"
#include "flutter/fml/synchronization/waitable_event.h"
#include "flutter/fml/time/time_delta.h"
#include "flutter/fml/time/time_point.h"
@@ -73,8 +74,9 @@ TEST_F(VsyncWaiterTest, AwaitVsync) {
fml::AutoResetWaitableEvent latch;
vsync_waiter->AsyncWaitForVsync(
[&latch](fml::TimePoint frame_start_time,
fml::TimePoint frame_target_time) { latch.Signal(); });
[&latch](std::unique_ptr<flutter::FrameTimingsRecorder> recorder) {
latch.Signal();
});
SignalVsyncEvent();
bool did_timeout =