commit faf3ded90b625a3a304c22d1574bea9d408dec57
author Yiwei Zhang <zzyiwei@google.com> Wed May 02 17:37:17 2018 -0700
committer Yiwei Zhang <zzyiwei@google.com> Thu May 03 18:34:14 2018 -0700
tree f4e6c363506efd660db514c6129ba793251e96d0
parent 196b3d21468536d3bb18c562632272919ee5623f

SurfaceFlinger TimeStats Metrics

Add timestats metrics for SurfaceFlinger. Keep track of global metrics
like total frames, missed frames, frames fellback to client
compositions, etc, as well as layer timing metrics like the delta
combination of postTime, desiredPresentTime, acqureTime, latchTime,
presentTime, etc. This metric is aimed at GMScore.

Test: dumpsys SurfaceFlinger --timestats [go/sf-timestats for more args]
Bug: b/70388650
Change-Id: I6e4545aef62f7893020533a4e7521541ea453ecd

services/surfaceflinger/BufferLayer.cpp

diff --git a/services/surfaceflinger/BufferLayer.cpp b/services/surfaceflinger/BufferLayer.cpp
index 250c2f1..3c3eab6 100644
--- a/services/surfaceflinger/BufferLayer.cpp
+++ b/services/surfaceflinger/BufferLayer.cpp
@@ -311,6 +311,9 @@
     nsecs_t desiredPresentTime = mConsumer->getTimestamp();
     mFrameTracker.setDesiredPresentTime(desiredPresentTime);
 
+    const std::string layerName(getName().c_str());
+    mTimeStats.setDesiredTime(layerName, mCurrentFrameNumber, desiredPresentTime);
+
     std::shared_ptr<FenceTime> frameReadyFence = mConsumer->getCurrentFenceTime();
     if (frameReadyFence->isValid()) {
         mFrameTracker.setFrameReadyFence(std::move(frameReadyFence));
@@ -321,12 +324,15 @@
     }
 
     if (presentFence->isValid()) {
+        mTimeStats.setPresentFence(layerName, mCurrentFrameNumber, presentFence);
         mFrameTracker.setActualPresentFence(std::shared_ptr<FenceTime>(presentFence));
     } else {
         // The HWC doesn't support present fences, so use the refresh
         // timestamp instead.
-        mFrameTracker.setActualPresentTime(
-                mFlinger->getHwComposer().getRefreshTimestamp(HWC_DISPLAY_PRIMARY));
+        const nsecs_t actualPresentTime =
+                mFlinger->getHwComposer().getRefreshTimestamp(HWC_DISPLAY_PRIMARY);
+        mTimeStats.setPresentTime(layerName, mCurrentFrameNumber, actualPresentTime);
+        mFrameTracker.setActualPresentTime(actualPresentTime);
     }
 
     mFrameTracker.advanceFrame();
@@ -433,6 +439,7 @@
         // and return early
         if (queuedBuffer) {
             Mutex::Autolock lock(mQueueItemLock);
+            mTimeStats.removeTimeRecord(getName().c_str(), mQueueItems[0].mFrameNumber);
             mQueueItems.removeAt(0);
             android_atomic_dec(&mQueuedFrames);
         }
@@ -446,6 +453,7 @@
             Mutex::Autolock lock(mQueueItemLock);
             mQueueItems.clear();
             android_atomic_and(0, &mQueuedFrames);
+            mTimeStats.clearLayerRecord(getName().c_str());
         }
 
         // Once we have hit this state, the shadow queue may no longer
@@ -466,10 +474,15 @@
         // Remove any stale buffers that have been dropped during
         // updateTexImage
         while (mQueueItems[0].mFrameNumber != currentFrameNumber) {
+            mTimeStats.removeTimeRecord(getName().c_str(), mQueueItems[0].mFrameNumber);
             mQueueItems.removeAt(0);
             android_atomic_dec(&mQueuedFrames);
         }
 
+        const std::string layerName(getName().c_str());
+        mTimeStats.setAcquireFence(layerName, currentFrameNumber, mQueueItems[0].mFenceTime);
+        mTimeStats.setLatchTime(layerName, currentFrameNumber, latchTime);
+
         mQueueItems.removeAt(0);
     }