Loading services/surfaceflinger/Scheduler/EventThread.cpp +15 −8 Original line number Diff line number Diff line Loading @@ -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( Loading Loading @@ -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(), const auto scheduleResult = mVsyncRegistration.schedule( {.workDuration = mWorkDuration.get().count(), .readyDuration = mReadyDuration.count(), .lastVsync = mLastVsyncCallbackTime.ns()}); .lastVsync = mLastVsyncCallbackTime.ns(), .committedVsyncOpt = mLastCommittedVsyncTime.ns()}); LOG_ALWAYS_FATAL_IF(!scheduleResult, "Error scheduling callback"); } else { mVsyncRegistration.cancel(); Loading Loading @@ -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); } } Loading @@ -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) { Loading Loading @@ -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; } Loading services/surfaceflinger/Scheduler/EventThread.h +1 −0 Original line number Diff line number Diff line Loading @@ -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; Loading services/surfaceflinger/Scheduler/VSyncDispatch.h +4 −1 Original line number Diff line number Diff line Loading @@ -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. Loading @@ -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); } Loading services/surfaceflinger/Scheduler/VSyncDispatchTimerQueue.cpp +14 −6 Original line number Diff line number Diff line Loading @@ -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 = Loading Loading @@ -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(); } Loading Loading @@ -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", Loading Loading
services/surfaceflinger/Scheduler/EventThread.cpp +15 −8 Original line number Diff line number Diff line Loading @@ -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( Loading Loading @@ -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(), const auto scheduleResult = mVsyncRegistration.schedule( {.workDuration = mWorkDuration.get().count(), .readyDuration = mReadyDuration.count(), .lastVsync = mLastVsyncCallbackTime.ns()}); .lastVsync = mLastVsyncCallbackTime.ns(), .committedVsyncOpt = mLastCommittedVsyncTime.ns()}); LOG_ALWAYS_FATAL_IF(!scheduleResult, "Error scheduling callback"); } else { mVsyncRegistration.cancel(); Loading Loading @@ -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); } } Loading @@ -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) { Loading Loading @@ -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; } Loading
services/surfaceflinger/Scheduler/EventThread.h +1 −0 Original line number Diff line number Diff line Loading @@ -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; Loading
services/surfaceflinger/Scheduler/VSyncDispatch.h +4 −1 Original line number Diff line number Diff line Loading @@ -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. Loading @@ -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); } Loading
services/surfaceflinger/Scheduler/VSyncDispatchTimerQueue.cpp +14 −6 Original line number Diff line number Diff line Loading @@ -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 = Loading Loading @@ -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(); } Loading Loading @@ -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", Loading