SF: make FrameTimeline more robust for fence errors

- Emit a valid timestamp to Perfetto when fence signal time is invalid
- Mark pending fences as invalid if a newer fence has signaled

Test: SF unit tests
Bug: 243939707
Change-Id: Ieac7eb53fe3e36178d860cc0683bfd8fad7560cd

3 files changed, 79 insertions, 2 deletions

diff --git a/services/surfaceflinger/FrameTimeline/FrameTimeline.cpp b/services/surfaceflinger/FrameTimeline/FrameTimeline.cpp
index c73a75c756..cd1ba70d84 100644
--- a/services/surfaceflinger/FrameTimeline/FrameTimeline.cpp
+++ b/services/surfaceflinger/FrameTimeline/FrameTimeline.cpp
@@ -892,6 +892,10 @@ void FrameTimeline::DisplayFrame::classifyJank(nsecs_t& deadlineDelta, nsecs_t&
         mJankType = JankType::Unknown;
         deadlineDelta = 0;
         deltaToVsync = 0;
+        if (mSurfaceFlingerActuals.presentTime == Fence::SIGNAL_TIME_INVALID) {
+            mSurfaceFlingerActuals.presentTime = mSurfaceFlingerActuals.endTime;
+        }
+
         return;
     }
 
@@ -1168,22 +1172,50 @@ float FrameTimeline::computeFps(const std::unordered_set<int32_t>& layerIds) {
             static_cast<float>(totalPresentToPresentWalls);
 }
 
+std::optional<size_t> FrameTimeline::getFirstSignalFenceIndex() const {
+    for (size_t i = 0; i < mPendingPresentFences.size(); i++) {
+        const auto& [fence, _] = mPendingPresentFences[i];
+        if (fence && fence->isValid() && fence->getSignalTime() != Fence::SIGNAL_TIME_PENDING) {
+            return i;
+        }
+    }
+
+    return {};
+}
+
 void FrameTimeline::flushPendingPresentFences() {
+    const auto firstSignaledFence = getFirstSignalFenceIndex();
+    if (!firstSignaledFence.has_value()) {
+        return;
+    }
+
     // Perfetto is using boottime clock to void drifts when the device goes
     // to suspend.
     const auto monoBootOffset = mUseBootTimeClock
             ? (systemTime(SYSTEM_TIME_BOOTTIME) - systemTime(SYSTEM_TIME_MONOTONIC))
             : 0;
 
+    // Present fences are expected to be signaled in order. Mark all the previous
+    // pending fences as errors.
+    for (size_t i = 0; i < firstSignaledFence.value(); i++) {
+        const auto& pendingPresentFence = *mPendingPresentFences.begin();
+        const nsecs_t signalTime = Fence::SIGNAL_TIME_INVALID;
+        auto& displayFrame = pendingPresentFence.second;
+        displayFrame->onPresent(signalTime, mPreviousPresentTime);
+        displayFrame->trace(mSurfaceFlingerPid, monoBootOffset);
+        mPendingPresentFences.erase(mPendingPresentFences.begin());
+    }
+
     for (size_t i = 0; i < mPendingPresentFences.size(); i++) {
         const auto& pendingPresentFence = mPendingPresentFences[i];
         nsecs_t signalTime = Fence::SIGNAL_TIME_INVALID;
         if (pendingPresentFence.first && pendingPresentFence.first->isValid()) {
             signalTime = pendingPresentFence.first->getSignalTime();
             if (signalTime == Fence::SIGNAL_TIME_PENDING) {
-                continue;
+                break;
             }
         }
+
         auto& displayFrame = pendingPresentFence.second;
         displayFrame->onPresent(signalTime, mPreviousPresentTime);
         displayFrame->trace(mSurfaceFlingerPid, monoBootOffset);
diff --git a/services/surfaceflinger/FrameTimeline/FrameTimeline.h b/services/surfaceflinger/FrameTimeline/FrameTimeline.h
index a2305af554..31074b1959 100644
--- a/services/surfaceflinger/FrameTimeline/FrameTimeline.h
+++ b/services/surfaceflinger/FrameTimeline/FrameTimeline.h
@@ -474,6 +474,7 @@ private:
     friend class android::frametimeline::FrameTimelineTest;
 
     void flushPendingPresentFences() REQUIRES(mMutex);
+    std::optional<size_t> getFirstSignalFenceIndex() const REQUIRES(mMutex);
     void finalizeCurrentDisplayFrame() REQUIRES(mMutex);
     void dumpAll(std::string& result);
     void dumpJank(std::string& result);
diff --git a/services/surfaceflinger/tests/unittests/FrameTimelineTest.cpp b/services/surfaceflinger/tests/unittests/FrameTimelineTest.cpp
index 874fa7c766..f47ac6dc43 100644
--- a/services/surfaceflinger/tests/unittests/FrameTimelineTest.cpp
+++ b/services/surfaceflinger/tests/unittests/FrameTimelineTest.cpp
@@ -480,7 +480,7 @@ TEST_F(FrameTimelineTest, presentFenceSignaled_invalidSignalTime) {
     addEmptyDisplayFrame();
 
     auto displayFrame0 = getDisplayFrame(0);
-    EXPECT_EQ(displayFrame0->getActuals().presentTime, -1);
+    EXPECT_EQ(displayFrame0->getActuals().presentTime, 59);
     EXPECT_EQ(displayFrame0->getJankType(), JankType::Unknown);
     EXPECT_EQ(surfaceFrame1->getActuals().presentTime, -1);
     EXPECT_EQ(surfaceFrame1->getJankType(), JankType::Unknown);
@@ -2228,6 +2228,50 @@ TEST_F(FrameTimelineTest, jankClassification_displayFrameLateFinishLatePresent_G
     EXPECT_EQ(displayFrame2->getJankType(), JankType::SurfaceFlingerCpuDeadlineMissed);
 }
 
+TEST_F(FrameTimelineTest, jankClassification_presentFenceError) {
+    auto erroneousPresentFence1 = fenceFactory.createFenceTimeForTest(Fence::NO_FENCE);
+    auto erroneousPresentFence2 = fenceFactory.createFenceTimeForTest(Fence::NO_FENCE);
+    auto validPresentFence = fenceFactory.createFenceTimeForTest(Fence::NO_FENCE);
+    int64_t sfToken1 = mTokenManager->generateTokenForPredictions({22, 26, 40});
+    int64_t sfToken2 = mTokenManager->generateTokenForPredictions({52, 60, 60});
+    int64_t sfToken3 = mTokenManager->generateTokenForPredictions({72, 80, 80});
+
+    mFrameTimeline->setSfWakeUp(sfToken1, 22, Fps::fromPeriodNsecs(11));
+    mFrameTimeline->setSfPresent(26, erroneousPresentFence1);
+
+    mFrameTimeline->setSfWakeUp(sfToken2, 52, Fps::fromPeriodNsecs(11));
+    mFrameTimeline->setSfPresent(60, erroneousPresentFence2);
+
+    mFrameTimeline->setSfWakeUp(sfToken3, 72, Fps::fromPeriodNsecs(11));
+    mFrameTimeline->setSfPresent(80, validPresentFence);
+
+    validPresentFence->signalForTest(80);
+
+    addEmptyDisplayFrame();
+
+    {
+        auto displayFrame = getDisplayFrame(0);
+        EXPECT_EQ(displayFrame->getActuals().presentTime, 26);
+        EXPECT_EQ(displayFrame->getFramePresentMetadata(), FramePresentMetadata::UnknownPresent);
+        EXPECT_EQ(displayFrame->getFrameReadyMetadata(), FrameReadyMetadata::UnknownFinish);
+        EXPECT_EQ(displayFrame->getJankType(), JankType::Unknown);
+    }
+    {
+        auto displayFrame = getDisplayFrame(1);
+        EXPECT_EQ(displayFrame->getActuals().presentTime, 60);
+        EXPECT_EQ(displayFrame->getFramePresentMetadata(), FramePresentMetadata::UnknownPresent);
+        EXPECT_EQ(displayFrame->getFrameReadyMetadata(), FrameReadyMetadata::UnknownFinish);
+        EXPECT_EQ(displayFrame->getJankType(), JankType::Unknown);
+    }
+    {
+        auto displayFrame = getDisplayFrame(2);
+        EXPECT_EQ(displayFrame->getActuals().presentTime, 80);
+        EXPECT_EQ(displayFrame->getFramePresentMetadata(), FramePresentMetadata::OnTimePresent);
+        EXPECT_EQ(displayFrame->getFrameReadyMetadata(), FrameReadyMetadata::OnTimeFinish);
+        EXPECT_EQ(displayFrame->getJankType(), JankType::None);
+    }
+}
+
 TEST_F(FrameTimelineTest, computeFps_noLayerIds_returnsZero) {
     EXPECT_EQ(mFrameTimeline->computeFps({}), 0.0f);
 }