From f4cb0bf008a79606b848eb524184afe4ef6e9aa9 Mon Sep 17 00:00:00 2001 From: Nathan Rogers Date: Fri, 19 Feb 2021 09:11:04 -0800 Subject: [PATCH] Fix input flow event logic Add logic to handle the case of touch events that do not lead to frames. Previously, all touch event flow ids were queued in |Animator| until a frame was created, and then flowed into that frame. For no frame touch events, this would then cause metrics and trace visualization to erroneously associate the eventual frame with the original touch events. This issue is fixed by extending the Animator/VsyncWaiter's secondary vsync callback mechanism to support additional callbacks, and then using a secondary vsync callback to drain/end touch flow events when frames finish and no further frames are scheduled. Also add an additional flow step to |SmoothPointerDataDispatcher::DispatchPacket|. b/177250670 --- shell/common/animator.cc | 24 ++++++++++++++++++++++-- shell/common/animator.h | 13 +++++++++---- shell/common/engine.cc | 5 +++-- shell/common/engine.h | 3 ++- shell/common/pointer_data_dispatcher.cc | 8 ++++++++ shell/common/pointer_data_dispatcher.h | 12 +++++++----- shell/common/vsync_waiter.cc | 20 ++++++++++++-------- shell/common/vsync_waiter.h | 12 ++++++------ 8 files changed, 69 insertions(+), 28 deletions(-) diff --git a/shell/common/animator.cc b/shell/common/animator.cc index cacac38c12063..c2fc83e45d60e 100644 --- a/shell/common/animator.cc +++ b/shell/common/animator.cc @@ -80,6 +80,7 @@ void Animator::EnqueueTraceFlowId(uint64_t trace_flow_id) { return; } self->trace_flow_ids_.push_back(trace_flow_id); + self->ScheduleMaybeClearTraceFlowIds(); }); } @@ -249,8 +250,27 @@ void Animator::AwaitVSync() { delegate_.OnAnimatorNotifyIdle(dart_frame_deadline_); } -void Animator::ScheduleSecondaryVsyncCallback(const fml::closure& callback) { - waiter_->ScheduleSecondaryCallback(callback); +void Animator::ScheduleSecondaryVsyncCallback(uintptr_t id, + const fml::closure& callback) { + waiter_->ScheduleSecondaryCallback(id, callback); +} + +void Animator::ScheduleMaybeClearTraceFlowIds() { + waiter_->ScheduleSecondaryCallback( + reinterpret_cast(this), [self = weak_factory_.GetWeakPtr()] { + if (!self) { + return; + } + if (!self->frame_scheduled_ && !self->trace_flow_ids_.empty()) { + TRACE_EVENT0("flutter", + "Animator::ScheduleMaybeClearTraceFlowIds - callback"); + while (!self->trace_flow_ids_.empty()) { + auto flow_id = self->trace_flow_ids_.front(); + TRACE_FLOW_END("flutter", "PointerEvent", flow_id); + self->trace_flow_ids_.pop_front(); + } + } + }); } } // namespace flutter diff --git a/shell/common/animator.h b/shell/common/animator.h index cd2fff454e277..6927e85cc7aac 100644 --- a/shell/common/animator.h +++ b/shell/common/animator.h @@ -63,10 +63,11 @@ class Animator final { /// secondary callback will still be executed at vsync. /// /// This callback is used to provide the vsync signal needed by - /// `SmoothPointerDataDispatcher`. + /// `SmoothPointerDataDispatcher`, and for our own flow events. /// /// @see `PointerDataDispatcher::ScheduleSecondaryVsyncCallback`. - void ScheduleSecondaryVsyncCallback(const fml::closure& callback); + void ScheduleSecondaryVsyncCallback(uintptr_t id, + const fml::closure& callback); void Start(); @@ -74,8 +75,9 @@ class Animator final { void SetDimensionChangePending(); - // Enqueue |trace_flow_id| into |trace_flow_ids_|. The corresponding flow - // will be ended during the next |BeginFrame|. + // Enqueue |trace_flow_id| into |trace_flow_ids_|. The flow event will be + // ended at either the next frame, or the next vsync interval with no active + // active rendering. void EnqueueTraceFlowId(uint64_t trace_flow_id); private: @@ -91,6 +93,9 @@ class Animator final { const char* FrameParity(); + // Clear |trace_flow_ids_| if |frame_scheduled_| is false. + void ScheduleMaybeClearTraceFlowIds(); + Delegate& delegate_; TaskRunners task_runners_; std::shared_ptr waiter_; diff --git a/shell/common/engine.cc b/shell/common/engine.cc index 69b40b2c11ccb..14b30b322c345 100644 --- a/shell/common/engine.cc +++ b/shell/common/engine.cc @@ -515,8 +515,9 @@ void Engine::DoDispatchPacket(std::unique_ptr packet, } } -void Engine::ScheduleSecondaryVsyncCallback(const fml::closure& callback) { - animator_->ScheduleSecondaryVsyncCallback(callback); +void Engine::ScheduleSecondaryVsyncCallback(uintptr_t id, + const fml::closure& callback) { + animator_->ScheduleSecondaryVsyncCallback(id, callback); } void Engine::HandleAssetPlatformMessage(fml::RefPtr message) { diff --git a/shell/common/engine.h b/shell/common/engine.h index ec5778f99073c..10564764e201c 100644 --- a/shell/common/engine.h +++ b/shell/common/engine.h @@ -804,7 +804,8 @@ class Engine final : public RuntimeDelegate, uint64_t trace_flow_id) override; // |PointerDataDispatcher::Delegate| - void ScheduleSecondaryVsyncCallback(const fml::closure& callback) override; + void ScheduleSecondaryVsyncCallback(uintptr_t id, + const fml::closure& callback) override; //---------------------------------------------------------------------------- /// @brief Get the last Entrypoint that was used in the RunConfiguration diff --git a/shell/common/pointer_data_dispatcher.cc b/shell/common/pointer_data_dispatcher.cc index 8341ecec10ab2..78346a9d0ced3 100644 --- a/shell/common/pointer_data_dispatcher.cc +++ b/shell/common/pointer_data_dispatcher.cc @@ -4,6 +4,8 @@ #include "flutter/shell/common/pointer_data_dispatcher.h" +#include "flutter/fml/trace_event.h" + namespace flutter { PointerDataDispatcher::~PointerDataDispatcher() = default; @@ -16,12 +18,17 @@ SmoothPointerDataDispatcher::~SmoothPointerDataDispatcher() = default; void DefaultPointerDataDispatcher::DispatchPacket( std::unique_ptr packet, uint64_t trace_flow_id) { + TRACE_EVENT0("flutter", "DefaultPointerDataDispatcher::DispatchPacket"); + TRACE_FLOW_STEP("flutter", "PointerEvent", trace_flow_id); delegate_.DoDispatchPacket(std::move(packet), trace_flow_id); } void SmoothPointerDataDispatcher::DispatchPacket( std::unique_ptr packet, uint64_t trace_flow_id) { + TRACE_EVENT0("flutter", "SmoothPointerDataDispatcher::DispatchPacket"); + TRACE_FLOW_STEP("flutter", "PointerEvent", trace_flow_id); + if (is_pointer_data_in_progress_) { if (pending_packet_ != nullptr) { DispatchPendingPacket(); @@ -39,6 +46,7 @@ void SmoothPointerDataDispatcher::DispatchPacket( void SmoothPointerDataDispatcher::ScheduleSecondaryVsyncCallback() { delegate_.ScheduleSecondaryVsyncCallback( + reinterpret_cast(this), [dispatcher = weak_factory_.GetWeakPtr()]() { if (dispatcher && dispatcher->is_pointer_data_in_progress_) { if (dispatcher->pending_packet_ != nullptr) { diff --git a/shell/common/pointer_data_dispatcher.h b/shell/common/pointer_data_dispatcher.h index 208c8b0d2878e..7791292611130 100644 --- a/shell/common/pointer_data_dispatcher.h +++ b/shell/common/pointer_data_dispatcher.h @@ -53,14 +53,16 @@ class PointerDataDispatcher { /// by `Animator::RequestFrame`). /// /// Like the callback in `AsyncWaitForVsync`, this callback is - /// only scheduled to be called once, and it will be called in the - /// UI thread. If there is no AsyncWaitForVsync callback - /// (`Animator::RequestFrame` is not called), this secondary - /// callback will still be executed at vsync. + /// only scheduled to be called once per |id|, and it will be + /// called in the UI thread. If there is no AsyncWaitForVsync + /// callback (`Animator::RequestFrame` is not called), this + /// secondary callback will still be executed at vsync. /// /// This callback is used to provide the vsync signal needed by - /// `SmoothPointerDataDispatcher`. + /// `SmoothPointerDataDispatcher`, and for `Animator` input flow + /// events. virtual void ScheduleSecondaryVsyncCallback( + uintptr_t id, const fml::closure& callback) = 0; }; diff --git a/shell/common/vsync_waiter.cc b/shell/common/vsync_waiter.cc index 1bd8fdfaae658..f1cb89342874c 100644 --- a/shell/common/vsync_waiter.cc +++ b/shell/common/vsync_waiter.cc @@ -52,7 +52,7 @@ void VsyncWaiter::AsyncWaitForVsync(const Callback& callback) { return; } callback_ = std::move(callback); - if (secondary_callback_) { + if (!secondary_callbacks_.empty()) { // Return directly as `AwaitVSync` is already called by // `ScheduleSecondaryCallback`. return; @@ -61,7 +61,8 @@ void VsyncWaiter::AsyncWaitForVsync(const Callback& callback) { AwaitVSync(); } -void VsyncWaiter::ScheduleSecondaryCallback(const fml::closure& callback) { +void VsyncWaiter::ScheduleSecondaryCallback(uintptr_t id, + const fml::closure& callback) { FML_DCHECK(task_runners_.GetUITaskRunner()->RunsTasksOnCurrentThread()); if (!callback) { @@ -72,13 +73,13 @@ void VsyncWaiter::ScheduleSecondaryCallback(const fml::closure& callback) { { std::scoped_lock lock(callback_mutex_); - if (secondary_callback_) { + auto [_, inserted] = secondary_callbacks_.emplace(id, std::move(callback)); + if (!inserted) { // Multiple schedules must result in a single callback per frame interval. TRACE_EVENT_INSTANT0("flutter", "MultipleCallsToSecondaryVsyncInFrameInterval"); return; } - secondary_callback_ = std::move(callback); if (callback_) { // Return directly as `AwaitVSync` is already called by // `AsyncWaitForVsync`. @@ -91,15 +92,18 @@ void VsyncWaiter::ScheduleSecondaryCallback(const fml::closure& callback) { void VsyncWaiter::FireCallback(fml::TimePoint frame_start_time, fml::TimePoint frame_target_time) { Callback callback; - fml::closure secondary_callback; + std::vector secondary_callbacks; { std::scoped_lock lock(callback_mutex_); callback = std::move(callback_); - secondary_callback = std::move(secondary_callback_); + for (auto& pair : secondary_callbacks_) { + secondary_callbacks.push_back(std::move(pair.second)); + } + secondary_callbacks_.clear(); } - if (!callback && !secondary_callback) { + if (!callback && secondary_callbacks.empty()) { // This means that the vsync waiter implementation fired a callback for a // request we did not make. This is a paranoid check but we still want to // make sure we catch misbehaving vsync implementations. @@ -128,7 +132,7 @@ void VsyncWaiter::FireCallback(fml::TimePoint frame_start_time, frame_start_time); } - if (secondary_callback) { + for (auto& secondary_callback : secondary_callbacks) { task_runners_.GetUITaskRunner()->PostTaskForTime( std::move(secondary_callback), frame_start_time); } diff --git a/shell/common/vsync_waiter.h b/shell/common/vsync_waiter.h index b248449268c28..084399011df4b 100644 --- a/shell/common/vsync_waiter.h +++ b/shell/common/vsync_waiter.h @@ -8,6 +8,7 @@ #include #include #include +#include #include "flutter/common/task_runners.h" #include "flutter/fml/time/time_point.h" @@ -25,10 +26,11 @@ class VsyncWaiter : public std::enable_shared_from_this { void AsyncWaitForVsync(const Callback& callback); - /// Add a secondary callback for the next vsync. + /// Add a secondary callback for key |id| for the next vsync. /// - /// See also |PointerDataDispatcher::ScheduleSecondaryVsyncCallback|. - void ScheduleSecondaryCallback(const fml::closure& callback); + /// See also |PointerDataDispatcher::ScheduleSecondaryVsyncCallback| and + /// |Animator::ScheduleMaybeClearTraceFlowIds|. + void ScheduleSecondaryCallback(uintptr_t id, const fml::closure& callback); protected: // On some backends, the |FireCallback| needs to be made from a static C @@ -52,9 +54,7 @@ class VsyncWaiter : public std::enable_shared_from_this { private: std::mutex callback_mutex_; Callback callback_; - - std::mutex secondary_callback_mutex_; - fml::closure secondary_callback_; + std::unordered_map secondary_callbacks_; FML_DISALLOW_COPY_AND_ASSIGN(VsyncWaiter); };