commit 91f6df3b650507e04e43eb41feac02f5f92d16d0
author Alec Mouri <alecmouri@google.com> Thu Jan 30 08:48:58 2020 -0800
committer Alec Mouri <alecmouri@google.com> Fri Jan 31 12:59:35 2020 -0800
tree 4ef814e6f115d533fe8118ada41abd3f5292590d
parent 329f126bd5a78f66620dd0b113681e88192d51ed

[TimeStats] Expose pathological latch counters

* Missed latch because the acquire fence didn't fire
* Latched early because the desired present time was bad

Bug: 135478131
Test: libsurfaceflinger_unittest

Change-Id: Id02a62c222cb497c05889dd198be5fea6d64893a

services/surfaceflinger/BufferQueueLayer.cpp

diff --git a/services/surfaceflinger/BufferQueueLayer.cpp b/services/surfaceflinger/BufferQueueLayer.cpp
index b55e62b..bd8eafe 100644
--- a/services/surfaceflinger/BufferQueueLayer.cpp
+++ b/services/surfaceflinger/BufferQueueLayer.cpp
@@ -117,6 +117,10 @@
              "relative to expectedPresent %" PRId64,
              getDebugName(), addedTime, expectedPresentTime);
 
+    if (!isPlausible) {
+        mFlinger->mTimeStats->incrementBadDesiredPresent(getSequence());
+    }
+
     const bool isDue = addedTime < expectedPresentTime;
     return isDue || !isPlausible;
 }
@@ -154,7 +158,14 @@
         // able to be latched. To avoid this, grab this buffer anyway.
         return true;
     }
-    return mQueueItems[0].mFenceTime->getSignalTime() != Fence::SIGNAL_TIME_PENDING;
+    const bool fenceSignaled =
+            mQueueItems[0].mFenceTime->getSignalTime() != Fence::SIGNAL_TIME_PENDING;
+    if (!fenceSignaled) {
+        mFlinger->mTimeStats->incrementLatchSkipped(getSequence(),
+                                                    TimeStats::LatchSkipReason::LateAcquire);
+    }
+
+    return fenceSignaled;
 }
 
 bool BufferQueueLayer::framePresentTimeIsCurrent(nsecs_t expectedPresentTime) const {