BufferQueue/SF: Add OccupancyTracker

Adds an OccupancyTracker to BufferQueue. This module keeps track of
how many buffers are in the queue over time, which, in combination
with various aggregation of these statistics, allows SurfaceFlinger
to report what fraction of the time a given layer was double- or
triple-buffered.

Change-Id: Ida6e967dc5483c00a633e9fe03998e420dd88502
diff --git a/services/surfaceflinger/Layer.cpp b/services/surfaceflinger/Layer.cpp
index ed320cb..59a604a 100644
--- a/services/surfaceflinger/Layer.cpp
+++ b/services/surfaceflinger/Layer.cpp
@@ -1680,7 +1680,8 @@
     return mQueuedFrames > 0 || mSidebandStreamChanged || mAutoRefresh;
 }
 
-void Layer::onPostComposition() {
+bool Layer::onPostComposition() {
+    bool frameLatencyNeeded = mFrameLatencyNeeded;
     if (mFrameLatencyNeeded) {
         nsecs_t desiredPresentTime = mSurfaceFlingerConsumer->getTimestamp();
         mFrameTracker.setDesiredPresentTime(desiredPresentTime);
@@ -1712,6 +1713,7 @@
         mFrameTracker.advanceFrame();
         mFrameLatencyNeeded = false;
     }
+    return frameLatencyNeeded;
 }
 
 #ifdef USE_HWC2
@@ -2185,6 +2187,20 @@
     *outAcquireFence = mSurfaceFlingerConsumer->getCurrentFence();
     *outPrevReleaseFence = mSurfaceFlingerConsumer->getPrevReleaseFence();
 }
+
+std::vector<OccupancyTracker::Segment> Layer::getOccupancyHistory(
+        bool forceFlush) {
+    std::vector<OccupancyTracker::Segment> history;
+    status_t result = mSurfaceFlingerConsumer->getOccupancyHistory(forceFlush,
+            &history);
+    if (result != NO_ERROR) {
+        ALOGW("[%s] Failed to obtain occupancy history (%d)", mName.string(),
+                result);
+        return {};
+    }
+    return history;
+}
+
 // ---------------------------------------------------------------------------
 
 Layer::LayerCleaner::LayerCleaner(const sp<SurfaceFlinger>& flinger,
diff --git a/services/surfaceflinger/Layer.h b/services/surfaceflinger/Layer.h
index 7d085a4..79750a6 100644
--- a/services/surfaceflinger/Layer.h
+++ b/services/surfaceflinger/Layer.h
@@ -274,9 +274,10 @@
     bool onPreComposition();
 
     /*
-     *  called after composition.
+     * called after composition.
+     * returns true if the layer latched a new buffer this frame.
      */
-    void onPostComposition();
+    bool onPostComposition();
 
 #ifdef USE_HWC2
     // If a buffer was replaced this frame, release the former buffer
@@ -406,6 +407,8 @@
             bool* outIsGlesComposition, nsecs_t* outPostedTime,
             sp<Fence>* outAcquireFence, sp<Fence>* outPrevReleaseFence) const;
 
+    std::vector<OccupancyTracker::Segment> getOccupancyHistory(bool forceFlush);
+
 protected:
     // constant
     sp<SurfaceFlinger> mFlinger;
diff --git a/services/surfaceflinger/SurfaceFlinger.cpp b/services/surfaceflinger/SurfaceFlinger.cpp
index 91815f3..a730ac6 100644
--- a/services/surfaceflinger/SurfaceFlinger.cpp
+++ b/services/surfaceflinger/SurfaceFlinger.cpp
@@ -1049,7 +1049,11 @@
     const LayerVector& layers(mDrawingState.layersSortedByZ);
     const size_t count = layers.size();
     for (size_t i=0 ; i<count ; i++) {
-        layers[i]->onPostComposition();
+        bool frameLatched = layers[i]->onPostComposition();
+        if (frameLatched) {
+            recordBufferingStats(layers[i]->getName().string(),
+                    layers[i]->getOccupancyHistory(false));
+        }
     }
 
     sp<Fence> presentFence = mHwc->getRetireFence(HWC_DISPLAY_PRIMARY);
@@ -1641,6 +1645,8 @@
     if (!mLayersPendingRemoval.isEmpty()) {
         // Notify removed layers now that they can't be drawn from
         for (size_t i = 0; i < mLayersPendingRemoval.size(); i++) {
+            recordBufferingStats(mLayersPendingRemoval[i]->getName().string(),
+                    mLayersPendingRemoval[i]->getOccupancyHistory(true));
             mLayersPendingRemoval[i]->onRemoved();
         }
         mLayersPendingRemoval.clear();
@@ -2720,6 +2726,59 @@
             NUM_BUCKETS - 1, bucketTimeSec, percent);
 }
 
+void SurfaceFlinger::recordBufferingStats(const char* layerName,
+        std::vector<OccupancyTracker::Segment>&& history) {
+    Mutex::Autolock lock(mBufferingStatsMutex);
+    auto& stats = mBufferingStats[layerName];
+    for (const auto& segment : history) {
+        if (!segment.usedThirdBuffer) {
+            stats.twoBufferTime += segment.totalTime;
+        }
+        if (segment.occupancyAverage < 1.0f) {
+            stats.doubleBufferedTime += segment.totalTime;
+        } else if (segment.occupancyAverage < 2.0f) {
+            stats.tripleBufferedTime += segment.totalTime;
+        }
+        ++stats.numSegments;
+        stats.totalTime += segment.totalTime;
+    }
+}
+
+void SurfaceFlinger::dumpBufferingStats(String8& result) const {
+    result.append("Buffering stats:\n");
+    result.append("  [Layer name] <Active time> <Two buffer> "
+            "<Double buffered> <Triple buffered>\n");
+    Mutex::Autolock lock(mBufferingStatsMutex);
+    typedef std::tuple<std::string, float, float, float> BufferTuple;
+    std::map<float, BufferTuple, std::greater<float>> sorted;
+    for (const auto& statsPair : mBufferingStats) {
+        const char* name = statsPair.first.c_str();
+        const BufferingStats& stats = statsPair.second;
+        if (stats.numSegments == 0) {
+            continue;
+        }
+        float activeTime = ns2ms(stats.totalTime) / 1000.0f;
+        float twoBufferRatio = static_cast<float>(stats.twoBufferTime) /
+                stats.totalTime;
+        float doubleBufferRatio = static_cast<float>(
+                stats.doubleBufferedTime) / stats.totalTime;
+        float tripleBufferRatio = static_cast<float>(
+                stats.tripleBufferedTime) / stats.totalTime;
+        sorted.insert({activeTime, {name, twoBufferRatio,
+                doubleBufferRatio, tripleBufferRatio}});
+    }
+    for (const auto& sortedPair : sorted) {
+        float activeTime = sortedPair.first;
+        const BufferTuple& values = sortedPair.second;
+        result.appendFormat("  [%s] %.2f %.3f %.3f %.3f\n",
+                std::get<0>(values).c_str(), activeTime,
+                std::get<1>(values), std::get<2>(values),
+                std::get<3>(values));
+    }
+    result.append("\n");
+}
+
+
 void SurfaceFlinger::dumpAllLocked(const Vector<String16>& args, size_t& index,
         String8& result) const
 {
@@ -2773,6 +2832,8 @@
     dumpStaticScreenStats(result);
     result.append("\n");
 
+    dumpBufferingStats(result);
+
     /*
      * Dump the visible layer list
      */
diff --git a/services/surfaceflinger/SurfaceFlinger.h b/services/surfaceflinger/SurfaceFlinger.h
index 633e956..8263994 100644
--- a/services/surfaceflinger/SurfaceFlinger.h
+++ b/services/surfaceflinger/SurfaceFlinger.h
@@ -42,6 +42,7 @@
 
 #include <gui/ISurfaceComposer.h>
 #include <gui/ISurfaceComposerClient.h>
+#include <gui/OccupancyTracker.h>
 
 #include <hardware/hwcomposer_defs.h>
 
@@ -57,6 +58,9 @@
 #include "DisplayHardware/HWComposer.h"
 #include "Effects/Daltonizer.h"
 
+#include <map>
+#include <string>
+
 namespace android {
 
 // ---------------------------------------------------------------------------
@@ -432,6 +436,10 @@
 
     void dumpStaticScreenStats(String8& result) const;
 
+    void recordBufferingStats(const char* layerName,
+            std::vector<OccupancyTracker::Segment>&& history);
+    void dumpBufferingStats(String8& result) const;
+
     /* ------------------------------------------------------------------------
      * Attributes
      */
@@ -526,6 +534,29 @@
     nsecs_t mFrameBuckets[NUM_BUCKETS];
     nsecs_t mTotalTime;
     std::atomic<nsecs_t> mLastSwapTime;
+
+    // Double- vs. triple-buffering stats
+    struct BufferingStats {
+        BufferingStats()
+          : numSegments(0),
+            totalTime(0),
+            twoBufferTime(0),
+            doubleBufferedTime(0),
+            tripleBufferedTime(0) {}
+
+        size_t numSegments;
+        nsecs_t totalTime;
+
+        // "Two buffer" means that a third buffer was never used, whereas
+        // "double-buffered" means that on average the segment only used two
+        // buffers (though it may have used a third for some part of the
+        // segment)
+        nsecs_t twoBufferTime;
+        nsecs_t doubleBufferedTime;
+        nsecs_t tripleBufferedTime;
+    };
+    mutable Mutex mBufferingStatsMutex;
+    std::unordered_map<std::string, BufferingStats> mBufferingStats;
 };
 
 }; // namespace android
diff --git a/services/surfaceflinger/SurfaceFlinger_hwc1.cpp b/services/surfaceflinger/SurfaceFlinger_hwc1.cpp
index de46dfa..ef4861d 100644
--- a/services/surfaceflinger/SurfaceFlinger_hwc1.cpp
+++ b/services/surfaceflinger/SurfaceFlinger_hwc1.cpp
@@ -1042,7 +1042,11 @@
     const LayerVector& layers(mDrawingState.layersSortedByZ);
     const size_t count = layers.size();
     for (size_t i=0 ; i<count ; i++) {
-        layers[i]->onPostComposition();
+        bool frameLatched = layers[i]->onPostComposition();
+        if (frameLatched) {
+            recordBufferingStats(layers[i]->getName().string(),
+                    layers[i]->getOccupancyHistory(false));
+        }
     }
 
     const HWComposer& hwc = getHwComposer();
@@ -1670,6 +1674,8 @@
     if (!mLayersPendingRemoval.isEmpty()) {
         // Notify removed layers now that they can't be drawn from
         for (size_t i = 0; i < mLayersPendingRemoval.size(); i++) {
+            recordBufferingStats(mLayersPendingRemoval[i]->getName().string(),
+                    mLayersPendingRemoval[i]->getOccupancyHistory(true));
             mLayersPendingRemoval[i]->onRemoved();
         }
         mLayersPendingRemoval.clear();
@@ -2745,6 +2751,58 @@
             NUM_BUCKETS - 1, bucketTimeSec, percent);
 }
 
+void SurfaceFlinger::recordBufferingStats(const char* layerName,
+        std::vector<OccupancyTracker::Segment>&& history) {
+    Mutex::Autolock lock(mBufferingStatsMutex);
+    auto& stats = mBufferingStats[layerName];
+    for (const auto& segment : history) {
+        if (!segment.usedThirdBuffer) {
+            stats.twoBufferTime += segment.totalTime;
+        }
+        if (segment.occupancyAverage < 1.0f) {
+            stats.doubleBufferedTime += segment.totalTime;
+        } else if (segment.occupancyAverage < 2.0f) {
+            stats.tripleBufferedTime += segment.totalTime;
+        }
+        ++stats.numSegments;
+        stats.totalTime += segment.totalTime;
+    }
+}
+
+void SurfaceFlinger::dumpBufferingStats(String8& result) const {
+    result.append("Buffering stats:\n");
+    result.append("  [Layer name] <Active time> <Two buffer> "
+            "<Double buffered> <Triple buffered>\n");
+    Mutex::Autolock lock(mBufferingStatsMutex);
+    typedef std::tuple<std::string, float, float, float> BufferTuple;
+    std::map<float, BufferTuple, std::greater<float>> sorted;
+    for (const auto& statsPair : mBufferingStats) {
+        const char* name = statsPair.first.c_str();
+        const BufferingStats& stats = statsPair.second;
+        if (stats.numSegments == 0) {
+            continue;
+        }
+        float activeTime = ns2ms(stats.totalTime) / 1000.0f;
+        float twoBufferRatio = static_cast<float>(stats.twoBufferTime) /
+                stats.totalTime;
+        float doubleBufferRatio = static_cast<float>(
+                stats.doubleBufferedTime) / stats.totalTime;
+        float tripleBufferRatio = static_cast<float>(
+                stats.tripleBufferedTime) / stats.totalTime;
+        sorted.insert({activeTime, {name, twoBufferRatio,
+                doubleBufferRatio, tripleBufferRatio}});
+    }
+    for (const auto& sortedPair : sorted) {
+        float activeTime = sortedPair.first;
+        const BufferTuple& values = sortedPair.second;
+        result.appendFormat("  [%s] %.2f %.3f %.3f %.3f\n",
+                std::get<0>(values).c_str(), activeTime,
+                std::get<1>(values), std::get<2>(values),
+                std::get<3>(values));
+    }
+    result.append("\n");
+}
+
 void SurfaceFlinger::dumpAllLocked(const Vector<String16>& args, size_t& index,
         String8& result) const
 {
@@ -2796,6 +2854,8 @@
     dumpStaticScreenStats(result);
     result.append("\n");
 
+    dumpBufferingStats(result);
+
     /*
      * Dump the visible layer list
      */