commit 2e1608ff49148a8d99c2e33897fa0e5c3ce532c2
author Mikael Pessa <mikaelpessa@google.com> Fri Jul 19 11:25:35 2019 -0700
committer Mikael Pessa <mikaelpessa@google.com> Wed Aug 28 11:15:25 2019 -0700
tree 2ff7a03aa1db3c25e86490396e282135a59aed33
parent f0aa9016e99a441e2bc2048ddd55b1437b3f6daa

Add per-buffer perfetto trace points for SurfaceFlinger frame events

In order to track how buffers move through the system, we add per-buffer perfetto trace points for SurfaceFlinger.
The majority of these were already tracked through TimeStats, so the new tracing was built on top of TimeStats.

Test: atest libsurfaceflinger_unittest

Run trace with:
{ adb shell perfetto   -c - --txt   -o /data/misc/perfetto-traces/trace <<EOF
buffers: {
    size_kb: 1280
}
data_sources: {
    config {
        name: "android.surfaceflinger.timestats"
    }
}
duration_ms: 3000
EOF
} && adb pull /data/misc/perfetto-traces/trace ~/Desktop/trace

Change-Id: Ifb38c64a9966fece735f0ad72438c7c9c5e07baa

services/surfaceflinger/BufferQueueLayer.cpp

diff --git a/services/surfaceflinger/BufferQueueLayer.cpp b/services/surfaceflinger/BufferQueueLayer.cpp
index 5f494ff..6cad3c7 100644
--- a/services/surfaceflinger/BufferQueueLayer.cpp
+++ b/services/surfaceflinger/BufferQueueLayer.cpp
@@ -45,6 +45,14 @@
 
 void BufferQueueLayer::onLayerDisplayed(const sp<Fence>& releaseFence) {
     mConsumer->setReleaseFence(releaseFence);
+
+    // Prevent tracing the same release multiple times.
+    if (mPreviousFrameNumber != mPreviousReleasedFrameNumber) {
+        mFlinger->mTimeStats->traceFence(getSequence(), mPreviousBufferId, mPreviousFrameNumber,
+                                         std::make_shared<FenceTime>(releaseFence),
+                                         TimeStats::FrameEvent::RELEASE_FENCE);
+        mPreviousReleasedFrameNumber = mPreviousFrameNumber;
+    }
 }
 
 void BufferQueueLayer::setTransformHint(uint32_t orientation) const {
@@ -355,9 +363,15 @@
             mQueuedFrames--;
         }
 
+        uint64_t bufferID = mQueueItems[0].mGraphicBuffer->getId();
         mFlinger->mTimeStats->setAcquireFence(layerID, currentFrameNumber,
                                               mQueueItems[0].mFenceTime);
+        mFlinger->mTimeStats->traceFence(layerID, bufferID, currentFrameNumber,
+                                         mQueueItems[0].mFenceTime,
+                                         TimeStats::FrameEvent::ACQUIRE_FENCE);
         mFlinger->mTimeStats->setLatchTime(layerID, currentFrameNumber, latchTime);
+        mFlinger->mTimeStats->traceTimestamp(layerID, bufferID, currentFrameNumber, latchTime,
+                                             TimeStats::FrameEvent::LATCH);
 
         mQueueItems.removeAt(0);
     }
@@ -373,6 +387,7 @@
 
 status_t BufferQueueLayer::updateActiveBuffer() {
     // update the active buffer
+    mPreviousBufferId = getCurrentBufferId();
     mActiveBuffer = mConsumer->getCurrentBuffer(&mActiveBufferSlot, &mActiveBufferFence);
     auto& layerCompositionState = getCompositionLayer()->editState().frontEnd;
     layerCompositionState.buffer = mActiveBuffer;
@@ -413,6 +428,11 @@
 // -----------------------------------------------------------------------
 
 void BufferQueueLayer::onFrameAvailable(const BufferItem& item) {
+    const int32_t layerID = getSequence();
+    mFlinger->mTimeStats->traceNewLayer(layerID, getName().c_str());
+    mFlinger->mTimeStats->traceTimestamp(layerID, item.mGraphicBuffer->getId(), item.mFrameNumber,
+                                         systemTime(), TimeStats::FrameEvent::POST);
+
     ATRACE_CALL();
     // Add this buffer from our internal queue tracker
     { // Autolock scope