diff options
4 files changed, 34 insertions, 15 deletions
diff --git a/services/surfaceflinger/Scheduler/EventThread.cpp b/services/surfaceflinger/Scheduler/EventThread.cpp index d31fceab7e..218c56ef3d 100644 --- a/services/surfaceflinger/Scheduler/EventThread.cpp +++ b/services/surfaceflinger/Scheduler/EventThread.cpp @@ -320,7 +320,8 @@ void EventThread::setDuration(std::chrono::nanoseconds workDuration, mVsyncRegistration.update({.workDuration = mWorkDuration.get().count(), .readyDuration = mReadyDuration.count(), - .lastVsync = mLastVsyncCallbackTime.ns()}); + .lastVsync = mLastVsyncCallbackTime.ns(), + .committedVsyncOpt = mLastCommittedVsyncTime.ns()}); } sp<EventThreadConnection> EventThread::createEventConnection( @@ -527,10 +528,11 @@ void EventThread::threadMain(std::unique_lock<std::mutex>& lock) { } if (mState == State::VSync) { - const auto scheduleResult = - mVsyncRegistration.schedule({.workDuration = mWorkDuration.get().count(), - .readyDuration = mReadyDuration.count(), - .lastVsync = mLastVsyncCallbackTime.ns()}); + const auto scheduleResult = mVsyncRegistration.schedule( + {.workDuration = mWorkDuration.get().count(), + .readyDuration = mReadyDuration.count(), + .lastVsync = mLastVsyncCallbackTime.ns(), + .committedVsyncOpt = mLastCommittedVsyncTime.ns()}); LOG_ALWAYS_FATAL_IF(!scheduleResult, "Error scheduling callback"); } else { mVsyncRegistration.cancel(); @@ -725,8 +727,9 @@ void EventThread::dispatchEvent(const DisplayEventReceiver::Event& event, } if (event.header.type == DisplayEventReceiver::DISPLAY_EVENT_VSYNC && FlagManager::getInstance().vrr_config()) { - mCallback.onExpectedPresentTimePosted( - TimePoint::fromNs(event.vsync.vsyncData.preferredExpectedPresentationTime())); + mLastCommittedVsyncTime = + TimePoint::fromNs(event.vsync.vsyncData.preferredExpectedPresentationTime()); + mCallback.onExpectedPresentTimePosted(mLastCommittedVsyncTime); } } @@ -744,9 +747,12 @@ void EventThread::dump(std::string& result) const { const auto relativeLastCallTime = ticks<std::milli, float>(mLastVsyncCallbackTime - TimePoint::now()); + const auto relativeLastCommittedTime = + ticks<std::milli, float>(mLastCommittedVsyncTime - TimePoint::now()); StringAppendF(&result, "mWorkDuration=%.2f mReadyDuration=%.2f last vsync time ", mWorkDuration.get().count() / 1e6f, mReadyDuration.count() / 1e6f); StringAppendF(&result, "%.2fms relative to now\n", relativeLastCallTime); + StringAppendF(&result, " with vsync committed at %.2fms", relativeLastCommittedTime); StringAppendF(&result, " pending events (count=%zu):\n", mPendingEvents.size()); for (const auto& event : mPendingEvents) { @@ -794,7 +800,8 @@ scheduler::VSyncCallbackRegistration EventThread::onNewVsyncScheduleInternal( if (reschedule) { mVsyncRegistration.schedule({.workDuration = mWorkDuration.get().count(), .readyDuration = mReadyDuration.count(), - .lastVsync = mLastVsyncCallbackTime.ns()}); + .lastVsync = mLastVsyncCallbackTime.ns(), + .committedVsyncOpt = mLastCommittedVsyncTime.ns()}); } return oldRegistration; } diff --git a/services/surfaceflinger/Scheduler/EventThread.h b/services/surfaceflinger/Scheduler/EventThread.h index f772126349..bbe4f9d899 100644 --- a/services/surfaceflinger/Scheduler/EventThread.h +++ b/services/surfaceflinger/Scheduler/EventThread.h @@ -220,6 +220,7 @@ private: std::chrono::nanoseconds mReadyDuration GUARDED_BY(mMutex); std::shared_ptr<scheduler::VsyncSchedule> mVsyncSchedule GUARDED_BY(mMutex); TimePoint mLastVsyncCallbackTime GUARDED_BY(mMutex) = TimePoint::now(); + TimePoint mLastCommittedVsyncTime GUARDED_BY(mMutex) = TimePoint::now(); scheduler::VSyncCallbackRegistration mVsyncRegistration GUARDED_BY(mMutex); frametimeline::TokenManager* const mTokenManager; diff --git a/services/surfaceflinger/Scheduler/VSyncDispatch.h b/services/surfaceflinger/Scheduler/VSyncDispatch.h index 0c43ffbc04..8993c38d37 100644 --- a/services/surfaceflinger/Scheduler/VSyncDispatch.h +++ b/services/surfaceflinger/Scheduler/VSyncDispatch.h @@ -93,6 +93,8 @@ public: * readyDuration will typically be 0. * @lastVsync: The targeted display time. This will be snapped to the closest * predicted vsync time after lastVsync. + * @committedVsyncOpt: The display time that is committed to the callback as the + * target vsync time. * * callback will be dispatched at 'workDuration + readyDuration' nanoseconds before a vsync * event. @@ -101,10 +103,11 @@ public: nsecs_t workDuration = 0; nsecs_t readyDuration = 0; nsecs_t lastVsync = 0; + std::optional<nsecs_t> committedVsyncOpt; bool operator==(const ScheduleTiming& other) const { return workDuration == other.workDuration && readyDuration == other.readyDuration && - lastVsync == other.lastVsync; + lastVsync == other.lastVsync && committedVsyncOpt == other.committedVsyncOpt; } bool operator!=(const ScheduleTiming& other) const { return !(*this == other); } diff --git a/services/surfaceflinger/Scheduler/VSyncDispatchTimerQueue.cpp b/services/surfaceflinger/Scheduler/VSyncDispatchTimerQueue.cpp index 900bce0aa9..1925f1165c 100644 --- a/services/surfaceflinger/Scheduler/VSyncDispatchTimerQueue.cpp +++ b/services/surfaceflinger/Scheduler/VSyncDispatchTimerQueue.cpp @@ -103,7 +103,8 @@ ScheduleResult VSyncDispatchTimerQueueEntry::schedule(VSyncDispatch::ScheduleTim tracker.nextAnticipatedVSyncTimeFrom(std::max(timing.lastVsync, now + timing.workDuration + timing.readyDuration), - timing.lastVsync); + timing.committedVsyncOpt.value_or( + timing.lastVsync)); auto nextWakeupTime = nextVsyncTime - timing.workDuration - timing.readyDuration; bool const wouldSkipAVsyncTarget = @@ -208,9 +209,12 @@ void VSyncDispatchTimerQueueEntry::update(VSyncTracker& tracker, nsecs_t now) { const auto workDelta = mWorkloadUpdateInfo->workDuration - mScheduleTiming.workDuration; const auto readyDelta = mWorkloadUpdateInfo->readyDuration - mScheduleTiming.readyDuration; const auto lastVsyncDelta = mWorkloadUpdateInfo->lastVsync - mScheduleTiming.lastVsync; + const auto lastCommittedVsyncDelta = + mWorkloadUpdateInfo->committedVsyncOpt.value_or(mWorkloadUpdateInfo->lastVsync) - + mScheduleTiming.committedVsyncOpt.value_or(mScheduleTiming.lastVsync); SFTRACE_FORMAT_INSTANT("Workload updated workDelta=%" PRId64 " readyDelta=%" PRId64 - " lastVsyncDelta=%" PRId64, - workDelta, readyDelta, lastVsyncDelta); + " lastVsyncDelta=%" PRId64 " committedVsyncDelta=%" PRId64, + workDelta, readyDelta, lastVsyncDelta, lastCommittedVsyncDelta); mScheduleTiming = *mWorkloadUpdateInfo; mWorkloadUpdateInfo.reset(); } @@ -261,10 +265,14 @@ void VSyncDispatchTimerQueueEntry::dump(std::string& result) const { StringAppendF(&result, "\t\t%s: %s %s\n", mName.c_str(), mRunning ? "(in callback function)" : "", armedInfo.c_str()); StringAppendF(&result, - "\t\t\tworkDuration: %.2fms readyDuration: %.2fms lastVsync: %.2fms relative " - "to now\n", + "\t\t\tworkDuration: %.2fms readyDuration: %.2fms " + "lastVsync: %.2fms relative to now " + "committedVsync: %.2fms relative to now\n", mScheduleTiming.workDuration / 1e6f, mScheduleTiming.readyDuration / 1e6f, - (mScheduleTiming.lastVsync - systemTime()) / 1e6f); + (mScheduleTiming.lastVsync - systemTime()) / 1e6f, + (mScheduleTiming.committedVsyncOpt.value_or(mScheduleTiming.lastVsync) - + systemTime()) / + 1e6f); if (mLastDispatchTime) { StringAppendF(&result, "\t\t\tmLastDispatchTime: %.2fms ago\n", |