From e46243a906d09b2d404e2e2e2e5d44370e903eaf Mon Sep 17 00:00:00 2001 From: Ady Abraham Date: Tue, 23 Feb 2021 19:33:49 -0800 Subject: SurfaceFlinger: mExpectedPresentTime should not be updated outside the main thread mExpectedPresentTime should be set only by the main thread when composition starts as it is used throughout the composition stage, and updates to this variable may cause SF to use inconsistent values for determining the expected present time. Test: Run TouchLatency app and observe systraces Test: Expand notification shade and observe systraces Bug: 178148035 Change-Id: Ie221d7e1fb0b0965460af773d3ecf0b06b5c5d7a --- services/surfaceflinger/SurfaceFlinger.cpp | 159 ++++++++++----------- services/surfaceflinger/SurfaceFlinger.h | 4 + .../tests/unittests/TransactionApplicationTest.cpp | 37 ++--- 3 files changed, 90 insertions(+), 110 deletions(-) diff --git a/services/surfaceflinger/SurfaceFlinger.cpp b/services/surfaceflinger/SurfaceFlinger.cpp index 7e41915444..487988b715 100644 --- a/services/surfaceflinger/SurfaceFlinger.cpp +++ b/services/surfaceflinger/SurfaceFlinger.cpp @@ -3279,6 +3279,7 @@ void SurfaceFlinger::flushTransactionQueues() { transactions.push_back(transaction); } mTransactionQueue.pop(); + ATRACE_INT("TransactionQueue", mTransactionQueue.size()); } } @@ -3353,102 +3354,51 @@ bool SurfaceFlinger::transactionIsReadyToBeApplied( return ready; } -status_t SurfaceFlinger::setTransactionState( - const FrameTimelineInfo& frameTimelineInfo, const Vector& states, - const Vector& displays, uint32_t flags, const sp& applyToken, - const InputWindowCommands& inputWindowCommands, int64_t desiredPresentTime, - bool isAutoTimestamp, const client_cache_t& uncacheBuffer, bool hasListenerCallbacks, - const std::vector& listenerCallbacks, uint64_t transactionId) { - ATRACE_CALL(); - - uint32_t permissions = - callingThreadHasUnscopedSurfaceFlingerAccess() ? Permission::ACCESS_SURFACE_FLINGER : 0; - // Avoid checking for rotation permissions if the caller already has ACCESS_SURFACE_FLINGER - // permissions. - if ((permissions & Permission::ACCESS_SURFACE_FLINGER) || - callingThreadHasRotateSurfaceFlingerAccess()) { - permissions |= Permission::ROTATE_SURFACE_FLINGER; - } - - const int64_t postTime = systemTime(); - - IPCThreadState* ipc = IPCThreadState::self(); - const int originPid = ipc->getCallingPid(); - const int originUid = ipc->getCallingUid(); - - { - Mutex::Autolock _l(mQueueLock); - // If its TransactionQueue already has a pending TransactionState or if it is pending - auto itr = mPendingTransactionQueues.find(applyToken); - // if this is an animation frame, wait until prior animation frame has - // been applied by SF - if (flags & eAnimation) { - while (itr != mPendingTransactionQueues.end()) { - status_t err = mTransactionQueueCV.waitRelative(mQueueLock, s2ns(5)); - if (CC_UNLIKELY(err != NO_ERROR)) { - ALOGW_IF(err == TIMED_OUT, - "setTransactionState timed out " - "waiting for animation frame to apply"); - break; - } - itr = mPendingTransactionQueues.find(applyToken); - } - } +void SurfaceFlinger::queueTransaction(TransactionState state) { + Mutex::Autolock _l(mQueueLock); - const bool pendingTransactions = itr != mPendingTransactionQueues.end(); - // Expected present time is computed and cached on invalidate, so it may be stale. - if (!pendingTransactions) { - const auto now = systemTime(); - const bool nextVsyncPending = now < mExpectedPresentTime.load(); - const DisplayStatInfo stats = mScheduler->getDisplayStatInfo(now); - mExpectedPresentTime = calculateExpectedPresentTime(stats); - // The transaction might arrive just before the next vsync but after - // invalidate was called. In that case we need to get the next vsync - // afterwards. - if (nextVsyncPending) { - mExpectedPresentTime += stats.vsyncPeriod; + // If its TransactionQueue already has a pending TransactionState or if it is pending + auto itr = mPendingTransactionQueues.find(state.applyToken); + // if this is an animation frame, wait until prior animation frame has + // been applied by SF + if (state.flags & eAnimation) { + while (itr != mPendingTransactionQueues.end()) { + status_t err = mTransactionQueueCV.waitRelative(mQueueLock, s2ns(5)); + if (CC_UNLIKELY(err != NO_ERROR)) { + ALOGW_IF(err == TIMED_OUT, + "setTransactionState timed out " + "waiting for animation frame to apply"); + break; } + itr = mPendingTransactionQueues.find(state.applyToken); } + } - mTransactionQueue.emplace(frameTimelineInfo, states, displays, flags, applyToken, - inputWindowCommands, desiredPresentTime, isAutoTimestamp, - uncacheBuffer, postTime, permissions, hasListenerCallbacks, - listenerCallbacks, originPid, originUid, transactionId); - - if (pendingTransactions || - (!isAutoTimestamp && desiredPresentTime > mExpectedPresentTime.load())) { - setTransactionFlags(eTransactionFlushNeeded); - return NO_ERROR; - } - - // TODO(b/159125966): Remove eEarlyWakeup completely as no client should use this flag - if (flags & eEarlyWakeup) { - ALOGW("eEarlyWakeup is deprecated. Use eExplicitEarlyWakeup[Start|End]"); - } - - if (!(permissions & Permission::ACCESS_SURFACE_FLINGER) && - (flags & (eExplicitEarlyWakeupStart | eExplicitEarlyWakeupEnd))) { - ALOGE("Only WindowManager is allowed to use eExplicitEarlyWakeup[Start|End] flags"); - flags &= ~(eExplicitEarlyWakeupStart | eExplicitEarlyWakeupEnd); - } + mTransactionQueue.emplace(state); + ATRACE_INT("TransactionQueue", mTransactionQueue.size()); - const auto schedule = [](uint32_t flags) { - if (flags & eEarlyWakeup) return TransactionSchedule::Early; - if (flags & eExplicitEarlyWakeupEnd) return TransactionSchedule::EarlyEnd; - if (flags & eExplicitEarlyWakeupStart) return TransactionSchedule::EarlyStart; - return TransactionSchedule::Late; - }(flags); - setTransactionFlags(eTransactionFlushNeeded, schedule); + // TODO(b/159125966): Remove eEarlyWakeup completely as no client should use this flag + if (state.flags & eEarlyWakeup) { + ALOGW("eEarlyWakeup is deprecated. Use eExplicitEarlyWakeup[Start|End]"); } - // if this is a synchronous transaction, wait for it to take effect - // before returning. - const bool synchronous = flags & eSynchronous; - const bool syncInput = inputWindowCommands.syncInputWindows; - if (!synchronous && !syncInput) { - return NO_ERROR; + if (!(state.permissions & Permission::ACCESS_SURFACE_FLINGER) && + (state.flags & (eExplicitEarlyWakeupStart | eExplicitEarlyWakeupEnd))) { + ALOGE("Only WindowManager is allowed to use eExplicitEarlyWakeup[Start|End] flags"); + state.flags &= ~(eExplicitEarlyWakeupStart | eExplicitEarlyWakeupEnd); } + const auto schedule = [](uint32_t flags) { + if (flags & eEarlyWakeup) return TransactionSchedule::Early; + if (flags & eExplicitEarlyWakeupEnd) return TransactionSchedule::EarlyEnd; + if (flags & eExplicitEarlyWakeupStart) return TransactionSchedule::EarlyStart; + return TransactionSchedule::Late; + }(state.flags); + + setTransactionFlags(eTransactionFlushNeeded, schedule); +} + +void SurfaceFlinger::waitForSynchronousTransaction(bool synchronous, bool syncInput) { Mutex::Autolock _l(mStateLock); if (synchronous) { mTransactionPending = true; @@ -3472,6 +3422,41 @@ status_t SurfaceFlinger::setTransactionState( break; } } +} + +status_t SurfaceFlinger::setTransactionState( + const FrameTimelineInfo& frameTimelineInfo, const Vector& states, + const Vector& displays, uint32_t flags, const sp& applyToken, + const InputWindowCommands& inputWindowCommands, int64_t desiredPresentTime, + bool isAutoTimestamp, const client_cache_t& uncacheBuffer, bool hasListenerCallbacks, + const std::vector& listenerCallbacks, uint64_t transactionId) { + ATRACE_CALL(); + + uint32_t permissions = + callingThreadHasUnscopedSurfaceFlingerAccess() ? Permission::ACCESS_SURFACE_FLINGER : 0; + // Avoid checking for rotation permissions if the caller already has ACCESS_SURFACE_FLINGER + // permissions. + if ((permissions & Permission::ACCESS_SURFACE_FLINGER) || + callingThreadHasRotateSurfaceFlingerAccess()) { + permissions |= Permission::ROTATE_SURFACE_FLINGER; + } + + const int64_t postTime = systemTime(); + + IPCThreadState* ipc = IPCThreadState::self(); + const int originPid = ipc->getCallingPid(); + const int originUid = ipc->getCallingUid(); + + queueTransaction({frameTimelineInfo, states, displays, flags, applyToken, inputWindowCommands, + desiredPresentTime, isAutoTimestamp, uncacheBuffer, postTime, permissions, + hasListenerCallbacks, listenerCallbacks, originPid, originUid, + transactionId}); + + const bool synchronous = flags & eSynchronous; + const bool syncInput = inputWindowCommands.syncInputWindows; + if (synchronous || syncInput) { + waitForSynchronousTransaction(synchronous, syncInput); + } return NO_ERROR; } diff --git a/services/surfaceflinger/SurfaceFlinger.h b/services/surfaceflinger/SurfaceFlinger.h index 1cb16306a7..f73a13d67c 100644 --- a/services/surfaceflinger/SurfaceFlinger.h +++ b/services/surfaceflinger/SurfaceFlinger.h @@ -1036,6 +1036,10 @@ private: // either AID_GRAPHICS or AID_SYSTEM. status_t CheckTransactCodeCredentials(uint32_t code); + // Add transaction to the Transaction Queue + void queueTransaction(TransactionState state) EXCLUDES(mQueueLock); + void waitForSynchronousTransaction(bool synchronous, bool syncInput) EXCLUDES(mStateLock); + /* * Generic Layer Metadata */ diff --git a/services/surfaceflinger/tests/unittests/TransactionApplicationTest.cpp b/services/surfaceflinger/tests/unittests/TransactionApplicationTest.cpp index eb2c1baca7..7c431a077b 100644 --- a/services/surfaceflinger/tests/unittests/TransactionApplicationTest.cpp +++ b/services/surfaceflinger/tests/unittests/TransactionApplicationTest.cpp @@ -127,7 +127,6 @@ public: ASSERT_EQ(0u, mFlinger.getTransactionQueue().size()); // called in SurfaceFlinger::signalTransaction EXPECT_CALL(*mMessageQueue, invalidate()).Times(1); - EXPECT_CALL(*mVSyncTracker, nextAnticipatedVSyncTimeFrom(_)).WillOnce(Return(systemTime())); TransactionInfo transaction; setupSingle(transaction, flags, syncInputWindows, /*desiredPresentTime*/ systemTime(), /*isAutoTimestamp*/ true, @@ -163,8 +162,6 @@ public: // first check will see desired present time has not passed, // but afterwards it will look like the desired present time has passed nsecs_t time = systemTime(); - EXPECT_CALL(*mVSyncTracker, nextAnticipatedVSyncTimeFrom(_)) - .WillOnce(Return(time + nsecs_t(5 * 1e8))); TransactionInfo transaction; setupSingle(transaction, flags, syncInputWindows, /*desiredPresentTime*/ time + s2ns(1), false, FrameTimelineInfo{}); @@ -177,7 +174,11 @@ public: transaction.id); nsecs_t returnedTime = systemTime(); - EXPECT_LE(returnedTime, applicationSentTime + s2ns(5)); + if ((flags & ISurfaceComposer::eSynchronous) || syncInputWindows) { + EXPECT_GE(systemTime(), applicationSentTime + s2ns(5)); + } else { + EXPECT_LE(returnedTime, applicationSentTime + s2ns(5)); + } // This transaction should have been placed on the transaction queue auto transactionQueue = mFlinger.getTransactionQueue(); EXPECT_EQ(1u, transactionQueue.size()); @@ -187,9 +188,11 @@ public: ASSERT_EQ(0u, mFlinger.getTransactionQueue().size()); // called in SurfaceFlinger::signalTransaction nsecs_t time = systemTime(); - EXPECT_CALL(*mMessageQueue, invalidate()).Times(1); - EXPECT_CALL(*mVSyncTracker, nextAnticipatedVSyncTimeFrom(_)) - .WillOnce(Return(time + nsecs_t(5 * 1e8))); + if (!syncInputWindows) { + EXPECT_CALL(*mMessageQueue, invalidate()).Times(2); + } else { + EXPECT_CALL(*mMessageQueue, invalidate()).Times(1); + } // transaction that should go on the pending thread TransactionInfo transactionA; setupSingle(transactionA, /*flags*/ 0, /*syncInputWindows*/ false, @@ -229,7 +232,8 @@ public: // if this is an animation, this thread should be blocked for 5s // in setTransactionState waiting for transactionA to flush. Otherwise, // the transaction should be placed on the pending queue - if (flags & ISurfaceComposer::eAnimation) { + if (flags & (ISurfaceComposer::eAnimation | ISurfaceComposer::eSynchronous) || + syncInputWindows) { EXPECT_GE(systemTime(), applicationSentTime + s2ns(5)); } else { EXPECT_LE(systemTime(), applicationSentTime + s2ns(5)); @@ -238,18 +242,9 @@ public: // transaction that would goes to pending transaciton queue. mFlinger.flushTransactionQueues(); - // check that there is one binder on the pending queue. + // check that the transaction was applied. auto transactionQueue = mFlinger.getPendingTransactionQueue(); - EXPECT_EQ(1u, transactionQueue.size()); - - auto& [applyToken, transactionStates] = *(transactionQueue.begin()); - EXPECT_EQ(2u, transactionStates.size()); - - auto& transactionStateA = transactionStates.front(); - transactionStates.pop(); - checkEqual(transactionA, transactionStateA); - auto& transactionStateB = transactionStates.front(); - checkEqual(transactionB, transactionStateB); + EXPECT_EQ(0u, transactionQueue.size()); } bool mHasListenerCallbacks = false; @@ -262,10 +257,6 @@ TEST_F(TransactionApplicationTest, Flush_RemovesFromQueue) { // called in SurfaceFlinger::signalTransaction EXPECT_CALL(*mMessageQueue, invalidate()).Times(1); - // nsecs_t time = systemTime(); - EXPECT_CALL(*mVSyncTracker, nextAnticipatedVSyncTimeFrom(_)) - .WillOnce(Return(nsecs_t(5 * 1e8))) - .WillOnce(Return(s2ns(2))); TransactionInfo transactionA; // transaction to go on pending queue setupSingle(transactionA, /*flags*/ 0, /*syncInputWindows*/ false, /*desiredPresentTime*/ s2ns(1), false, FrameTimelineInfo{}); -- cgit v1.2.3-59-g8ed1b