commit 5facfb12bea41da2546468b7a1680a606a01e0a6
author Ady Abraham <adyabr@google.com> Wed Apr 22 15:18:31 2020 -0700
committer Ady Abraham <adyabr@google.com> Thu Apr 23 13:44:11 2020 -0700
tree 07a72c8f5cd2666cf529e09c26f2a9a0d080d6d6
parent a0bb096dc6af57fdc944260409d1d75d10103276

SurfaceFlinger: expected present time directly from VSyncReactor

When SurfaceFlinger calculates what is the vsync time, it does
that by asking VSyncReactor what is next anticipated vsync from the
wake up time. To handle negative offsets (when SF wakes up more than
a vsync period before a vsync event) SF adds a vsync period
to that anticipated vsync.

This creates a race condition where the offset used at the
time of invalidate may be different than the offset used by
VSyncReactor calculated at the time of the requestNextVsync().
To fix that, we plumb the first calculated vsync time to
SurfaceFlinger.

Bug: 154303002
Test: Run app transitions and collect systrace
Change-Id: I3f2670c7b0ecb52a85fb07df6d360694b51d5d66

services/surfaceflinger/Scheduler/EventThread.cpp

diff --git a/services/surfaceflinger/Scheduler/EventThread.cpp b/services/surfaceflinger/Scheduler/EventThread.cpp
index 8347650..5dedb6a 100644
--- a/services/surfaceflinger/Scheduler/EventThread.cpp
+++ b/services/surfaceflinger/Scheduler/EventThread.cpp
@@ -79,8 +79,9 @@
                                 event.hotplug.connected ? "connected" : "disconnected");
         case DisplayEventReceiver::DISPLAY_EVENT_VSYNC:
             return StringPrintf("VSync{displayId=%" ANDROID_PHYSICAL_DISPLAY_ID_FORMAT
-                                ", count=%u}",
-                                event.header.displayId, event.vsync.count);
+                                ", count=%u, expectedVSyncTimestamp=%" PRId64 "}",
+                                event.header.displayId, event.vsync.count,
+                                event.vsync.expectedVSyncTimestamp);
         case DisplayEventReceiver::DISPLAY_EVENT_CONFIG_CHANGED:
             return StringPrintf("ConfigChanged{displayId=%" ANDROID_PHYSICAL_DISPLAY_ID_FORMAT
                                 ", configId=%u}",
@@ -99,10 +100,11 @@
 }
 
 DisplayEventReceiver::Event makeVSync(PhysicalDisplayId displayId, nsecs_t timestamp,
-                                      uint32_t count) {
+                                      uint32_t count, nsecs_t expectedVSyncTimestamp) {
     DisplayEventReceiver::Event event;
     event.header = {DisplayEventReceiver::DISPLAY_EVENT_VSYNC, displayId, timestamp};
     event.vsync.count = count;
+    event.vsync.expectedVSyncTimestamp = expectedVSyncTimestamp;
     return event;
 }
 
@@ -312,11 +314,12 @@
     mCondition.notify_all();
 }
 
-void EventThread::onVSyncEvent(nsecs_t timestamp) {
+void EventThread::onVSyncEvent(nsecs_t timestamp, nsecs_t expectedVSyncTimestamp) {
     std::lock_guard<std::mutex> lock(mMutex);
 
     LOG_FATAL_IF(!mVSyncState);
-    mPendingEvents.push_back(makeVSync(mVSyncState->displayId, timestamp, ++mVSyncState->count));
+    mPendingEvents.push_back(makeVSync(mVSyncState->displayId, timestamp, ++mVSyncState->count,
+                                       expectedVSyncTimestamp));
     mCondition.notify_all();
 }
 
@@ -423,7 +426,8 @@
         } else {
             // Generate a fake VSYNC after a long timeout in case the driver stalls. When the
             // display is off, keep feeding clients at 60 Hz.
-            const auto timeout = mState == State::SyntheticVSync ? 16ms : 1000ms;
+            const std::chrono::nanoseconds timeout =
+                    mState == State::SyntheticVSync ? 16ms : 1000ms;
             if (mCondition.wait_for(lock, timeout) == std::cv_status::timeout) {
                 if (mState == State::VSync) {
                     ALOGW("Faking VSYNC due to driver stall for thread %s", mThreadName);
@@ -439,9 +443,10 @@
                 }
 
                 LOG_FATAL_IF(!mVSyncState);
-                mPendingEvents.push_back(makeVSync(mVSyncState->displayId,
-                                                   systemTime(SYSTEM_TIME_MONOTONIC),
-                                                   ++mVSyncState->count));
+                const auto now = systemTime(SYSTEM_TIME_MONOTONIC);
+                const auto expectedVSyncTime = now + timeout.count();
+                mPendingEvents.push_back(makeVSync(mVSyncState->displayId, now,
+                                                   ++mVSyncState->count, expectedVSyncTime));
             }
         }
     }